Closed mietzen closed 1 year ago
I ran it again with debug logging:
2023/09/02 09:24:58 DEBUG dynamic_dns found DNS record {"type": "A", "name": "wireguard.home.mietzen.xyz", "zone": "mietzen.xyz", "value": "xxx.xxx.xxx.123"}
2023/09/02 09:24:58 DEBUG dynamic_dns found DNS record {"type": "A", "name": "home-assistant.home.mietzen.xyz", "zone": "mietzen.xyz", "value": "xxx.xxx.xxx.123"}
2023/09/02 09:24:58 DEBUG dynamic_dns found DNS record {"type": "A", "name": "vaultwarden.home.mietzen.xyz", "zone": "mietzen.xyz", "value": "xxx.xxx.xxx.123"}
2023/09/02 09:24:58 DEBUG dynamic_dns found DNS record {"type": "A", "name": "wireguard.home.mietzen.xyz", "zone": "mietzen.xyz", "value": "xxx.xxx.xxx.172"}
2023/09/02 09:24:58 DEBUG dynamic_dns found DNS record {"type": "A", "name": "home-assistant.home.mietzen.xyz", "zone": "mietzen.xyz", "value": "xxx.xxx.xxx.172"}
2023/09/02 09:24:58 DEBUG dynamic_dns found DNS record {"type": "A", "name": "vaultwarden.home.mietzen.xyz", "zone": "mietzen.xyz", "value": "xxx.xxx.xxx.172"}
2023/09/02 09:24:58 INFO dynamic_dns domain not found in DNS {"domain": "wireguard.home.mietzen.xyz"}
2023/09/02 09:24:58 INFO dynamic_dns domain not found in DNS {"domain": "wireguard.home.mietzen.xyz"}
2023/09/02 09:24:58 INFO dynamic_dns domain not found in DNS {"domain": "home-assistant.home.mietzen.xyz"}
2023/09/02 09:24:58 INFO dynamic_dns domain not found in DNS {"domain": "home-assistant.home.mietzen.xyz"}
2023/09/02 09:24:58 INFO dynamic_dns domain not found in DNS {"domain": "vaultwarden.home.mietzen.xyz"}
2023/09/02 09:24:58 INFO dynamic_dns domain not found in DNS {"domain": "vaultwarden.home.mietzen.xyz"}
2023/09/02 09:24:58 DEBUG dynamic_dns looked up current IPs from DNS {"lastIPs": {"home-assistant.home.mietzen.xyz":{"A":[""],"AAAA":[""]},"vaultwarden.home.mietzen.xyz":{"A":[""],"AAAA":[""]},"wireguard.home.mietzen.xyz":{"A":[""],"AAAA":[""]}}}
2023/09/02 09:24:58 DEBUG dynamic_dns.ip_sources.command running command {"command": "/opt/CaddyV2/fritzbox_ext_ip", "args": ["192.168.178.1"], "dir": "", "timeout": 30000000000}
2023/09/02 09:24:59 DEBUG dynamic_dns.ip_sources.command parsed ip succesfull {"command": "/opt/CaddyV2/fritzbox_ext_ip", "args": ["192.168.178.1"], "stdout": "xxx.xxx.xxx.172\n", "ip": "xxx.xxx.xxx.172"}
2023/09/02 09:24:59 INFO dynamic_dns updating DNS record {"zone": "mietzen.xyz", "type": "A", "name": "wireguard.home", "value": "xxx.xxx.xxx.172", "ttl": 3600}
2023/09/02 09:24:59 INFO dynamic_dns updating DNS record {"zone": "mietzen.xyz", "type": "A", "name": "home-assistant.home", "value": "xxx.xxx.xxx.172", "ttl": 3600}
2023/09/02 09:24:59 INFO dynamic_dns updating DNS record {"zone": "mietzen.xyz", "type": "A", "name": "vaultwarden.home", "value": "xxx.xxx.xxx.172", "ttl": 3600}
2023/09/02 09:25:00 INFO dynamic_dns finished updating DNS {"current_ips": ["xxx.xxx.xxx.172"]}
dynamic_dns
seems to find the records, but doesn't associate them with the ones it should update.
2023/09/02 09:24:58 DEBUG dynamic_dns found DNS record {"type": "A", "name": "wireguard.home.mietzen.xyz", "zone": "mietzen.xyz", "value": "xxx.xxx.xxx.123"}
...
2023/09/02 09:24:58 INFO dynamic_dns domain not found in DNS {"domain": "wireguard.home.mietzen.xyz"}
...
2023/09/02 09:24:58 DEBUG dynamic_dns looked up current IPs from DNS {"lastIPs": {"home-assistant.home.mietzen.xyz":{"A":[""],"AAAA":[""]},"vaultwarden.home.mietzen.xyz":{"A":[""],"AAAA":[""]},"wireguard.home.mietzen.xyz":{"A":[""],"AAAA":[""]}}}
...
2023/09/02 09:24:59 INFO dynamic_dns updating DNS record {"zone": "mietzen.xyz", "type": "A", "name": "wireguard.home", "value": "xxx.xxx.xxx.172", "ttl": 3600}
My best guess is that zone
and name
are not properly handled by: https://github.com/libdns/porkbun or https://github.com/caddy-dns/porkbun
Since it includes the zone
in the name
and dynamic_dns
expects the name
to not include the zone
, is this right?
Yep, this must be a problem with https://github.com/libdns/porkbun because this plugin uses SetRecords
which implies that existing records should be replaced instead of appended.
I just ran into this with the Namecheap provider, too.
@francislavoie Isn't there an issue in this repo though ("lookupCurrentIPsFromDNS") that causes the "domain not found in DNS" in the first place? Even with a "SetRecords" fix in the provider, this will continue to happen.
In fact, in this case, it will update the "current" records map with a null IP, even when one exists. Just a hunch, but this might influence DNS providers in the "SetRecords" call to believe there isn't an outstanding record (sure, you could argue it could independently verify) for the affected zone(s) which might be the cause of this whole thing.
@whirlthesquirrel To make sure I understand, are you suggesting that the records passed into SetRecords()
have different values (a different name and type)? As far as I can tell, that would be the only way to append instead of replace, at least with a correct implementation of SetRecords.
@mholt I think I was reading too much into the "domain not found in DNS" logging and didn't see the post-processing that takes place before the call to "SetRecords".
Here are my log entries in debug:
caddy | {"level":"debug","ts":1694021296.4225838,"logger":"dynamic_dns","msg":"found DNS record","type":"A","name":"*","zone":"example.com","value":"old_ip"}
caddy | {"level":"debug","ts":1694021296.4226384,"logger":"dynamic_dns","msg":"found DNS record","type":"A","name":"@","zone":"example.com","value":"unrelated_ip"}
caddy | {"level":"debug","ts":1694021296.4226441,"logger":"dynamic_dns","msg":"found DNS record","type":"A","name":"www","zone":"example.com","value":"unrelated_ip"}
caddy | {"level":"info","ts":1694021296.4226513,"logger":"dynamic_dns","msg":"domain not found in DNS","domain":"*.example.com"}
caddy | {"level":"info","ts":1694021296.4226577,"logger":"dynamic_dns","msg":"domain not found in DNS","domain":"*.example.com"}
caddy | {"level":"debug","ts":1694021296.4226687,"logger":"dynamic_dns","msg":"looked up current IPs from DNS","lastIPs":{"*.example.com":{"A":["old_ip"],"AAAA":[""]}}}
caddy | {"level":"debug","ts":1694021296.6638966,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup","type":"IPv4","endpoint":"https://api64.ipify.org","ip":"new_ip"}
caddy | {"level":"info","ts":1694021296.6639485,"logger":"dynamic_dns","msg":"updating DNS record","zone":"example.com","type":"A","name":"*","value":"new_ip","ttl":0}
caddy | {"level":"info","ts":1694021296.6639616,"logger":"dynamic_dns","msg":"updating DNS record","zone":"example.com","type":"A","name":"*","value":"new_ip","ttl":0}
caddy | {"level":"info","ts":1694021297.377286,"logger":"dynamic_dns","msg":"finished updating DNS","current_ips":["new_ip"]}
I'm not sure I understand why there is two updates on the same record (or if it's still just one call to "SetRecords"), but I suppose that's not really related to this issue?
type
logging on the domain not found in DNS
message, so that explains the doubling there, since one is for A and the other for AAAAupdating DNS record
logs, that definitely does mean there's two records in the slice. Probably need more logs in the steps of the loop at https://github.com/mholt/caddy-dynamicdns/blob/3cdd858980a495596e96ece0d666cd1ddba61fb0/dynamicdns.go#L204 to get a better idea why it's appending twice. If you want to clone the repo and add some additional logging statements to test locally that would help reveal what's going on.I updated the logging to log the record type as you mentioned (I was thinking the same thing too), along with the current IPs.
From when there was no previously existing A record:
caddy | {"level":"debug","ts":1694096804.235109,"logger":"dynamic_dns","msg":"found DNS record","type":"A","name":"@","zone":"example.com","value":"unrelated_ip"}
caddy | {"level":"debug","ts":1694096804.2352726,"logger":"dynamic_dns","msg":"found DNS record","type":"A","name":"www","zone":"example.com","value":"unrelated_ip"}
caddy | {"level":"info","ts":1694096804.2352831,"logger":"dynamic_dns","msg":"domain not found in DNS","domain":"*.example.com","type":"A"}
caddy | {"level":"info","ts":1694096804.2352898,"logger":"dynamic_dns","msg":"domain not found in DNS","domain":"*.example.com","type":"AAAA"}
caddy | {"level":"debug","ts":1694096804.2353253,"logger":"dynamic_dns","msg":"looked up current IPs from DNS","lastIPs":{"*.example.com":{"A":[""],"AAAA":[""]}}}
caddy | {"level":"debug","ts":1694096804.417885,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup","type":"IPv4","endpoint":"https://api64.ipify.org","ip":"new_ip"}
caddy | {"level":"debug","ts":1694096804.4179177,"logger":"dynamic_dns","msg":"found current IP","value":"new_ip","type":"A"}
caddy | {"level":"info","ts":1694096804.4179363,"logger":"dynamic_dns","msg":"updating DNS record","zone":"example.com","type":"A","name":"*","value":"new_ip","ttl":0}
caddy | {"level":"info","ts":1694096805.7142298,"logger":"dynamic_dns","msg":"finished updating DNS","current_ips":["new_ip"]}
From when there was a single, outdated A record:
caddy | {"level":"debug","ts":1694096926.982758,"logger":"dynamic_dns","msg":"found DNS record","type":"A","name":"*","zone":"example.com","value":"old_ip"}
caddy | {"level":"debug","ts":1694096926.9828343,"logger":"dynamic_dns","msg":"found DNS record","type":"A","name":"@","zone":"example.com","value":"unrelated_ip"}
caddy | {"level":"debug","ts":1694096926.9828475,"logger":"dynamic_dns","msg":"found DNS record","type":"A","name":"www","zone":"example.com","value":"unrelated_ip"}
caddy | {"level":"info","ts":1694096926.9828606,"logger":"dynamic_dns","msg":"domain not found in DNS","domain":"*.example.com","type":"AAAA"}
caddy | {"level":"debug","ts":1694096926.9828837,"logger":"dynamic_dns","msg":"looked up current IPs from DNS","lastIPs":{"*.example.com":{"A":["old_ip"],"AAAA":[""]}}}
caddy | {"level":"debug","ts":1694096927.2460074,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup","type":"IPv4","endpoint":"https://api64.ipify.org","ip":"new_ip"}
caddy | {"level":"debug","ts":1694096927.24605,"logger":"dynamic_dns","msg":"found current IP","value":"new_ip","type":"A"}
caddy | {"level":"info","ts":1694096927.2460687,"logger":"dynamic_dns","msg":"updating DNS record","zone":"example.com","type":"A","name":"*","value":"new_ip","ttl":0}
caddy | {"level":"info","ts":1694096928.0516918,"logger":"dynamic_dns","msg":"finished updating DNS","current_ips":["new_ip"]}
From when the new record has already been appended with the existing, outdated A record:
caddy | {"level":"debug","ts":1694096065.9506721,"logger":"dynamic_dns","msg":"found DNS record","type":"A","name":"*","zone":"example.com","value":"old_ip"}
caddy | {"level":"debug","ts":1694096065.9507217,"logger":"dynamic_dns","msg":"found DNS record","type":"A","name":"*","zone":"example.com","value":"new_ip"}
caddy | {"level":"debug","ts":1694096065.950729,"logger":"dynamic_dns","msg":"found DNS record","type":"A","name":"@","zone":"example.com","value":"unrelated_ip"}
caddy | {"level":"debug","ts":1694096065.9507356,"logger":"dynamic_dns","msg":"found DNS record","type":"A","name":"www","zone":"example.com","value":"unrelated_ip"}
caddy | {"level":"info","ts":1694096065.950744,"logger":"dynamic_dns","msg":"domain not found in DNS","domain":"*.example.com","type":"AAAA"}
caddy | {"level":"debug","ts":1694096065.9507565,"logger":"dynamic_dns","msg":"looked up current IPs from DNS","lastIPs":{"*.example.com":{"A":["new_ip"],"AAAA":[""]}}}
caddy | {"level":"debug","ts":1694096066.222695,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup","type":"IPv4","endpoint":"https://api64.ipify.org","ip":"new_ip"}
caddy | {"level":"debug","ts":1694096066.222732,"logger":"dynamic_dns","msg":"found current IP","value":"new_ip","type":"A"}
caddy | {"level":"debug","ts":1694096066.2227442,"logger":"dynamic_dns","msg":"no IP address change; no update needed"}
That's strange, because from the log I posted before, it looks like the middle case would be the one to reproduce the same behavior (2 "domain not found in DNS" entries, assuming "A" and "AAAA"?), which didn't this time. Not sure what's going on there and how it's different from before.
Should "domain not found in DNS" be emitted on "AAAA" records when only "versions ipv4" is specified?
Also, Namecheap has the concept of a "Dynamic DNS password", which is separate from an API key. To use the API, you have to have a whitelisted client IP. I believe Caddy was able to update the records without whitelisting, but not fetch the existing ones without the client IP being whitelisted. If fetching existing records is a requirement for proper functionality here, and since whitelisting a new IP would have to be done manually, it seems counter-intuitive to use an API key for dynamic DNS. Something to think about if the current DNS provider interface is not sufficient to solve this, as it would unnecessarily update every time.
Not sure what's going on there and how it's different from before.
:man_shrugging: I guess you're saying you can't replicate the problem after adjusting the logging?
Should "domain not found in DNS" be emitted on "AAAA" records when only "versions ipv4" is specified?
Probably not. An oversight when I implemented that I guess. PR is welcome if you want to adjust it :+1:
I believe Caddy was able to update the records without whitelisting, but not fetch the existing ones without the client IP being whitelisted.
:scream: that seems backwards... write operations should have "higher security" than read operations.
Either way I'd just argue "Namecheap's API is dumb and bad, and there's not much we can do about that".
🤷♂️ I guess you're saying you can't replicate the problem after adjusting the logging?
Unfortunately, yeah. 😞
😱 that seems backwards... write operations should have "higher security" than read operations.
Either way I'd just argue "Namecheap's API is dumb and bad, and there's not much we can do about that".
Honestly, fair enough! 😆 Thanks for your help.
I'm using
dynamic_dns
withprovider porkbun
the A records are created, but instead of overwriting the old IP with with the new one, the old entrie is left untouched and a new one is created.DNS-Entries
OS: OPNsense 23.7.3-amd64