manche Emails gehen nicht raus (Domain abhängig), Host not found

[tkhode]

Salve,

ich nutze seit Jahren PMG 8.1.2 als Single Node Lösung vor einem Exchange Server und zerbreche mit seit Tagen den Kopf über folgendes Problem...
Urplötzlich und ohne (wissentliche) Konfigurationsänderung gehen Emails an bestimmte Empfänger Domänen nicht mehr raus.

im Syslog taucht als Fehler auf: dsn=4.4.3, status=deferred (Host or domain name not found. Name service error for name=XYZ.DE type=MX: Host not found, try again)

Herausgefunden habe ich, es liegt am DNS.... komischerweise funktionieren alle Empfänger solange diese nicht bei arcor/ vodafone/EWE (soweit mein Stand) beheimatet sind. (es bleiben also z.B. Emails hängen die z.B. an *@arcor.de gehen, aber auch Empfänger Domänen die z.B. lediglich z.B. mx.vodafone.de als MX haben bleiben hängen

nslookup an der pmg Console bringt bei den problematischen Domänen, immer:

root@pmg:~# nslookup arcor.de
;; communications error to 127.0.0.1#53: timed out
;; communications error to 127.0.0.1#53: timed out
;; communications error to 127.0.0.1#53: timed out
;; no servers could be reached

alle sonstigen (also die allerallermeisten) Domänen funktionieren aber !

hier ergibt ein nslookup als Beispiel ein:

root@pmg:~# nslookup heise.de
Server: 127.0.0.1
Address: 127.0.0.1#53

Non-authoritative answer:
Name: heise.de
Address: 193.99.144.80
Name: heise.de
Address: 2a02:2e0:3fe:1001:302::

(PMG Admin Handbuch insbesondere - "Installing and using unbound" habe ich gelesen)

z.B. ergibt ein "dig a proxmox.com @127.0.0.1 +short " an der Console als Ergebnis die : 212.224.123.69 (-> i.O. )

Wie kann ich der Ursache auf die Spur kommen und im besten Fall abstellen.... ?

freue mich auf hilfreiche TIps !

Grüße, Thorsten

 

[Stoiko Ivanov]

root@pmg:~# nslookup arcor.de
;; communications error to 127.0.0.1#53: timed out

der konfigurierte DNS-server scheint auf localhost zu laufen - mit `ss -ulnp` herausfinden welcher prozess auf udp port 53 lauscht - und dessen logs ansehen.... z.b. im fall von unbound: `journalctl -u unbound`

 

[tkhode]

Hallo Stoiko,
vielen Dank für Deine Antwort.
Das ss hatte ich auch schon gemacht, und es ergibt:

root@pmg:~# ss -tulnp | grep :53

udp UNCONN 0 0 127.0.0.1:53 0.0.0.0:* users("unbound",pid=677,fd=5))
udp UNCONN 0 0 [::1]:53 [::]:* users("unbound",pid=677,fd=3))
tcp LISTEN 0 256 127.0.0.1:53 0.0.0.0:* users("unbound",pid=677,fd=6))
tcp LISTEN 0 256 [::1]:53 [::]:* users("unbound",pid=677,fd=4))
root@pmg:~#

journalctl -u unbound ergibt dann ein: (das Journal geht bis 16. Januar zurück, aber ich poste hier seit gestern Mittag)
=================

-- Boot 154c9a5caa3b45359db2304c78e33f77 --
Mar 27 12:02:13 pmg systemd[1]: Starting unbound.service - Unbound DNS server...
Mar 27 12:02:13 pmg unbound[692]: [692:0] notice: init module 0: subnetcache
Mar 27 12:02:13 pmg unbound[692]: [692:0] notice: init module 1: validator
Mar 27 12:02:13 pmg unbound[692]: [692:0] notice: init module 2: iterator
Mar 27 12:02:13 pmg unbound[692]: [692:0] info: start of service (unbound 1.17.1).
Mar 27 12:02:13 pmg systemd[1]: Started unbound.service - Unbound DNS server.
Mar 27 12:02:13 pmg unbound[692]: [692:0] info: generate keytag query _ta-4f66. NULL IN
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: service stopped (unbound 1.17.1).
Mar 27 12:29:15 pmg systemd[1]: Stopping unbound.service - Unbound DNS server...
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: server stats for thread 0: 2441 queries, 565 answers from cache, 1876 recursions, 0 prefetch, 0 rejected by>
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: server stats for thread 0: requestlist max 91 avg 31.1119 exceeded 0 jostled 0
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: average recursion processing time 10.113859 sec
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: histogram of recursion processing times
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: [25%]=0.0712797 median[50%]=0.120855 [75%]=0.249339
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: lower(secs) upper(secs) recursions
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 0.000000 0.000001 42
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 0.008192 0.016384 3
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 0.016384 0.032768 110
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 0.032768 0.065536 259
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 0.065536 0.131072 619
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 0.131072 0.262144 412
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 0.262144 0.524288 263
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 0.524288 1.000000 63
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 1.000000 2.000000 28
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 2.000000 4.000000 8
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 4.000000 8.000000 6
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 8.000000 16.000000 5
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 16.000000 32.000000 1
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 32.000000 64.000000 2
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 64.000000 128.000000 2
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 128.000000 256.000000 18
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 256.000000 512.000000 30
Mar 27 12:29:15 pmg unbound[692]: [692:0] info: 512.000000 1024.000000 2
Mar 27 12:29:15 pmg systemd[1]: unbound.service: Deactivated successfully.
Mar 27 12:29:15 pmg systemd[1]: Stopped unbound.service - Unbound DNS server.
Mar 27 12:29:15 pmg systemd[1]: unbound.service: Consumed 1.199s CPU time.
-- Boot c872beaa262f42bcaf4116c31e0d374b --
Mar 27 12:29:28 pmg systemd[1]: Starting unbound.service - Unbound DNS server...
Mar 27 12:29:28 pmg unbound[687]: [687:0] notice: init module 0: subnetcache
Mar 27 12:29:28 pmg unbound[687]: [687:0] notice: init module 1: validator
Mar 27 12:29:28 pmg unbound[687]: [687:0] notice: init module 2: iterator
Mar 27 12:29:28 pmg systemd[1]: Started unbound.service - Unbound DNS server.
Mar 27 12:29:28 pmg unbound[687]: [687:0] info: start of service (unbound 1.17.1).
Mar 27 12:29:34 pmg unbound[687]: [687:0] info: generate keytag query _ta-4f66. NULL IN
Mar 27 15:03:42 pmg systemd[1]: Stopping unbound.service - Unbound DNS server...
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: service stopped (unbound 1.17.1).
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: server stats for thread 0: 18964 queries, 5102 answers from cache, 13862 recursions, 0 prefetch, 0 rejected>
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: server stats for thread 0: requestlist max 206 avg 33.1195 exceeded 0 jostled 0
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: average recursion processing time 1.705206 sec
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: histogram of recursion processing times
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: [25%]=0.0645846 median[50%]=0.113568 [75%]=0.217181
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: lower(secs) upper(secs) recursions
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 0.000000 0.000001 436
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 0.004096 0.008192 1
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 0.008192 0.016384 43
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 0.016384 0.032768 1095
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 0.032768 0.065536 1946
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 0.065536 0.131072 4650
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 0.131072 0.262144 3383
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 0.262144 0.524288 1661
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 0.524288 1.000000 302
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 1.000000 2.000000 88
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 2.000000 4.000000 50
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 4.000000 8.000000 25
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 8.000000 16.000000 24
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 16.000000 32.000000 27
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 32.000000 64.000000 18
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 64.000000 128.000000 64
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 128.000000 256.000000 23
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 256.000000 512.000000 17
Mar 27 15:03:42 pmg unbound[687]: [687:0] info: 512.000000 1024.000000 5
Mar 27 15:03:42 pmg systemd[1]: unbound.service: Deactivated successfully.
Mar 27 15:03:42 pmg systemd[1]: Stopped unbound.service - Unbound DNS server.
Mar 27 15:03:42 pmg systemd[1]: unbound.service: Consumed 5.796s CPU time.
-- Boot e6065144e82e493a8e41b44a256d48b4 --
Mar 27 15:03:57 pmg systemd[1]: Starting unbound.service - Unbound DNS server...
Mar 27 15:03:57 pmg unbound[677]: [677:0] notice: init module 0: subnetcache
Mar 27 15:03:57 pmg unbound[677]: [677:0] notice: init module 1: validator
Mar 27 15:03:57 pmg unbound[677]: [677:0] notice: init module 2: iterator
Mar 27 15:03:57 pmg systemd[1]: Started unbound.service - Unbound DNS server.
Mar 27 15:03:57 pmg unbound[677]: [677:0] info: start of service (unbound 1.17.1).
Mar 27 15:03:58 pmg unbound[677]: [677:0] info: generate keytag query _ta-4f66. NULL IN
Mar 28 02:33:57 pmg unbound[677]: [677:0] info: generate keytag query _ta-4f66. NULL IN

======================================================

So auf meinen ersten Blick sehe ich hier keinen Fehler, habe allerdings (zu meiner Schande) auch nirgendwo einen 2. unbound - was hier normale Einträge wären...

Hast Du noch einen Hinweis/Idee dazu ?

vielen Dank & Gruß, Thorsten

 

[Stoiko Ivanov]

So auf meinen ersten Blick sehe ich hier keinen Fehler, habe allerdings (zu meiner Schande) auch nirgendwo einen 2. unbound - was hier normale Einträge wären...

sehe jetzt auch nix auffälliges (bin aber auch kein unbound experte... und es scheinen keine debug-logs von unbound aufgedreht zu sein - die würden wohl mehr verraten).

potentielle ideen für weiteres debugging:
* einfach einen anderen DNS-Server verwenden (der vom ISP, oder jener, der sonst so im Netzwerk verwendet wird, potentiell auch einfach google, cloudflare, quad-nine) - und schauen ob es dabei bleibt
* debug logs vom unbound einrichten und die logs ansehen.
* sicherstellen, dass nicht irgendein security-device (proxy, router, firewall, ...) die antworten fuer die spezifische domain unterbindet
* auf dem PMG die ganze delegation zu der betroffenen zone nachgehen - z.b. fuer proxmox.com:

dig +norec ns com @f.root-servers.net.
dig +norec ns proxmox.com @<<ip/name from answer above>
dig +norec mx proxmox.com @<ip/name from answer above>