TechnitiumSoftware / DnsServer

Technitium DNS Server
https://technitium.com/dns/
GNU General Public License v3.0
4.25k stars 418 forks source link

Repeated errors in logs #944

Closed drbobnz closed 3 months ago

drbobnz commented 3 months ago

Hi - I repeatedly get these error messages in my logs, am not sure if they are issues with Technitium DNS or not (or if this is normal or not) - any help appreciated!

  1. System.ArgumentException error - there's a lot of them
  2. DHCP address offers, a few seconds apart - note the weird character in the device name - but the device doesn't seem to accept the offer as far as I can tell
  3. DnsServerCore.Dns.DnsServerException: Failed to set records error (seems to relate to 4 below)
  4. Repeated DHCP Server updated DNS A record / DNS PTR record from one of our Apple TVs.

Log extracts below:

Issues 1 & 2 (short sample of long log): [2024-06-09 00:13:28 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:28 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:28 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:32 UTC] [0.0.0.0:68] System.ArgumentException: The array starting from the specified index is not long enough to read a value of the specified type. (Parameter 'value') at DnsServerCore.Dhcp.Options.ClientIdentifierOption.GetHashCode() in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\Options\ClientIdentifierOption.cs:line 118 at System.Collections.Concurrent.ConcurrentDictionary2.TryGetValue(TKey key, TValue& value) at DnsServerCore.Dhcp.Scope.GetOfferAsync(DhcpMessage request) in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\Scope.cs:line 948 at DnsServerCore.Dhcp.DhcpServer.ProcessDhcpMessageAsync(DhcpMessage request, IPEndPoint remoteEP, IPPacketInformation ipPacketInformation) in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\DhcpServer.cs:line 319 at DnsServerCore.Dhcp.DhcpServer.ProcessDhcpRequestAsync(DhcpMessage request, IPEndPoint remoteEP, IPPacketInformation ipPacketInformation, Socket udpListener) in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\DhcpServer.cs:line 249 [2024-06-09 00:13:32 UTC] [0.0.0.0:68] System.ArgumentException: The array starting from the specified index is not long enough to read a value of the specified type. (Parameter 'value') at DnsServerCore.Dhcp.Options.ClientIdentifierOption.GetHashCode() in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\Options\ClientIdentifierOption.cs:line 118 at System.Collections.Concurrent.ConcurrentDictionary2.TryGetValue(TKey key, TValue& value) at DnsServerCore.Dhcp.Scope.GetOfferAsync(DhcpMessage request) in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\Scope.cs:line 948 at DnsServerCore.Dhcp.DhcpServer.ProcessDhcpMessageAsync(DhcpMessage request, IPEndPoint remoteEP, IPPacketInformation ipPacketInformation) in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\DhcpServer.cs:line 319 at DnsServerCore.Dhcp.DhcpServer.ProcessDhcpRequestAsync(DhcpMessage request, IPEndPoint remoteEP, IPPacketInformation ipPacketInformation, Socket udpListener) in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\DhcpServer.cs:line 249 [2024-06-09 00:13:32 UTC] [0.0.0.0:68] System.ArgumentException: The array starting from the specified index is not long enough to read a value of the specified type. (Parameter 'value') at DnsServerCore.Dhcp.Options.ClientIdentifierOption.GetHashCode() in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\Options\ClientIdentifierOption.cs:line 118 at System.Collections.Concurrent.ConcurrentDictionary2.TryGetValue(TKey key, TValue& value) at DnsServerCore.Dhcp.Scope.GetOfferAsync(DhcpMessage request) in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\Scope.cs:line 948 at DnsServerCore.Dhcp.DhcpServer.ProcessDhcpMessageAsync(DhcpMessage request, IPEndPoint remoteEP, IPPacketInformation ipPacketInformation) in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\DhcpServer.cs:line 319 at DnsServerCore.Dhcp.DhcpServer.ProcessDhcpRequestAsync(DhcpMessage request, IPEndPoint remoteEP, IPPacketInformation ipPacketInformation, Socket udpListener) in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\DhcpServer.cs:line 249 [2024-06-09 00:13:32 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:32 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:32 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:34 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:34 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:34 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:40 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:40 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:40 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:45 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:45 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:45 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:50 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:50 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:50 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:57 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:57 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:13:57 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:03 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:03 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:03 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:05 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:05 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:05 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:12 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:12 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:12 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:14 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:14 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:14 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:19 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:19 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:19 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:22 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:22 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:22 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:27 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:27 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:27 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:30 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:30 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:30 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:36 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:36 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:36 UTC] [0.0.0.0:68] DHCP Server offered IP address [XXX.XXX.20.75] to Hub?? [AA-BB-CC-DD-EE-FF] for scope: VLAN20 [2024-06-09 00:14:40 UTC] [0.0.0.0:68] System.ArgumentException: The array starting from the specified index is not long enough to read a value of the specified type. (Parameter 'value') at DnsServerCore.Dhcp.Options.ClientIdentifierOption.GetHashCode() in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\Options\ClientIdentifierOption.cs:line 118 at System.Collections.Concurrent.ConcurrentDictionary2.TryGetValue(TKey key, TValue& value) at DnsServerCore.Dhcp.Scope.GetOfferAsync(DhcpMessage request) in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\Scope.cs:line 948 at DnsServerCore.Dhcp.DhcpServer.ProcessDhcpMessageAsync(DhcpMessage request, IPEndPoint remoteEP, IPPacketInformation ipPacketInformation) in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\DhcpServer.cs:line 319 at DnsServerCore.Dhcp.DhcpServer.ProcessDhcpRequestAsync(DhcpMessage request, IPEndPoint remoteEP, IPPacketInformation ipPacketInformation, Socket udpListener) in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\DhcpServer.cs:line 249

Issues 3 & 4: [2024-06-10 00:11:43 UTC] [0.0.0.0:68] DHCP Server leased IP address [XXX.XXX.1.68] to LoungeAppleTV [AA-BB-CC-DD-EE-FF] for scope: Home_LAN [2024-06-10 00:11:43 UTC] [0.0.0.0:68] DHCP Server leased IP address [XXX.XXX.1.68] to LoungeAppleTV [AA-BB-CC-DD-EE-FF] for scope: Home_LAN [2024-06-10 00:11:43 UTC] [0.0.0.0:68] DHCP Server leased IP address [XXX.XXX.1.68] to LoungeAppleTV [AA-BB-CC-DD-EE-FF] for scope: Home_LAN [2024-06-10 00:11:43 UTC] DHCP Server updated DNS A record 'loungeappletv.local' with IP address [XXX.XXX.1.68]. [2024-06-10 00:11:43 UTC] DHCP Server updated DNS PTR record '1.XXX.XXX.in-addr.arpa' with domain name 'loungeappletv.local'. [2024-06-10 00:11:43 UTC] DHCP Server updated DNS A record 'loungeappletv.local' with IP address [XXX.XXX.1.68]. [2024-06-10 00:11:43 UTC] DHCP Server updated DNS PTR record '1.XXX.XXX.in-addr.arpa' with domain name 'loungeappletv.local'. [2024-06-10 00:11:43 UTC] DnsServerCore.Dns.DnsServerException: Failed to set records. Please try again. at DnsServerCore.Dns.Zones.PrimarySubDomainZone.SetRecords(DnsResourceRecordType type, IReadOnlyList`1 records) in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dns\Zones\PrimarySubDomainZone.cs:line 97 at DnsServerCore.Dhcp.DhcpServer.UpdateDnsAuthZone(Boolean add, Scope scope, String domain, IPAddress address, Boolean isReservedLease) in Z:\Technitium\Projects\DnsServer\DnsServerCore\Dhcp\DhcpServer.cs:line 718 [2024-06-10 00:11:49 UTC] DHCP Server successfully saved scope file: /etc/dns/scopes/Home_LAN.scope [2024-06-10 00:11:54 UTC] Saved zone file for domain: local [2024-06-10 00:11:54 UTC] Saved zone file for domain: 1.XXX.XXX.in-addr.arpa [2024-06-10 00:12:14 UTC] [0.0.0.0:68] DHCP Server leased IP address [XXX.XXX.1.68] to LoungeAppleTV [AA-BB-CC-DD-EE-FF] for scope: Home_LAN [2024-06-10 00:12:14 UTC] [0.0.0.0:68] DHCP Server leased IP address [XXX.XXX.1.68] to LoungeAppleTV [AA-BB-CC-DD-EE-FF] for scope: Home_LAN [2024-06-10 00:12:14 UTC] [0.0.0.0:68] DHCP Server leased IP address [XXX.XXX.1.68] to LoungeAppleTV [AA-BB-CC-DD-EE-FF] for scope: Home_LAN [2024-06-10 00:12:14 UTC] DHCP Server updated DNS A record 'loungeappletv.local' with IP address [XXX.XXX.1.68]. [2024-06-10 00:12:14 UTC] DHCP Server updated DNS A record 'loungeappletv.local' with IP address [XXX.XXX.1.68]. [2024-06-10 00:12:14 UTC] DHCP Server updated DNS A record 'loungeappletv.local' with IP address [XXX.XXX.1.68]. [2024-06-10 00:12:14 UTC] DHCP Server updated DNS PTR record '68.1.XXX.XXX.in-addr.arpa' with domain name 'loungeappletv.local'. [2024-06-10 00:12:14 UTC] DHCP Server updated DNS PTR record '68.1.XXX.XXX.in-addr.arpa' with domain name 'loungeappletv.local'. [2024-06-10 00:12:14 UTC] DHCP Server updated DNS PTR record '68.1.XXX.XXX.in-addr.arpa' with domain name 'loungeappletv.local'. [2024-06-10 00:12:19 UTC] DHCP Server successfully saved scope file: /etc/dns/scopes/Home_LAN.scope [2024-06-10 00:12:24 UTC] Saved zone file for domain: local [2024-06-10 00:12:24 UTC] Saved zone file for domain: 1.XXX.XXX.in-addr.arpa

ShreyasZare commented 3 months ago

Thanks for reporting these issues. Will get them fixed in the upcoming update.

ShreyasZare commented 3 months ago

Technitium DNS Server v12.2.1 is now available that fixes this issue. Do update and let me know your feedback.

drbobnz commented 3 months ago

Thanks so much! I've updated today, will review the logs over the next day or so.

I also have another bug that I will probably log. Isn't related to this issue and this update didn't fix it (in short, if I reboot the server, DNS requests for devices for one network range fails until I untick 'Enable DNS-over-HTTPS', save settings, and then retick and save settings).

ShreyasZare commented 3 months ago

I also have another bug that I will probably log. Isn't related to this issue and this update didn't fix it (in short, if I reboot the server, DNS requests for devices for one network range fails until I untick 'Enable DNS-over-HTTPS', save settings, and then retick and save settings).

Do check the DNS logs to see if there are any errors logged for this. Share any error log you find.