Dynamic DNS + IPV6

animosity22 · February 22, 2023, 9:13pm

1. Caddy version:

v2.6.4 h1:2hwYqiRwk1tf3VruhMpLcYTg+11fCdr8S3jhNAdnPy8=

2. How I installed, and run Caddy:

xcaddy build with the plugins I use and runs as a single binary through systemd.

a. System environment:

Ubuntu 22.04 LTS
Linux phoenix 5.19.0-32-generic #33~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Mon Jan 30 17:03:34 UTC 2 x86_64 x86_64 x86_64 GNU/Linux

b. Command:

ExecStart=/opt/caddy/caddy run --environ --config /opt/caddy/Caddyfile

d. My not working part of my Caddy config:

        dynamic_dns {
                provider cloudflare {env.CLOUDFLARE_API_TOKEN}
                check_interval 5m
                domains {
                        blah.com hostname
                }
        }

3. The problem I’m having:

I’m not seeing my IPV6 address update and I’m not sure why. I tried running debug and that didn’t show me anything else. I tested a curl test to get my IPV6 and it shows up fine.

4. Error messages and/or full log output:

Feb 22 16:07:10 phoenix caddy[63932]: {"level":"info","ts":1677100030.1742177,"logger":"dynamic_dns","msg":"different IP address","new_ip":"1.2.3.4"}
Feb 22 16:07:10 phoenix caddy[63932]: {"level":"info","ts":1677100030.1743047,"logger":"dynamic_dns","msg":"updating DNS record","zone":"blah.com","type":"A","name":"home","value":"1.2.3.4","ttl":0}
Feb 22 16:07:10 phoenix caddy[63932]: {"level":"info","ts":1677100030.6577992,"logger":"dynamic_dns","msg":"finished updating DNS"}

5. What I already tried:

Restarting a few times as I’m not sure what else to test.

6. Links to relevant resources:

francislavoie · February 22, 2023, 10:00pm

Weird. Try setting versions ipv4 ipv6. I thought it should try both by default but maybe something changed

Also, enable the debug global option, it might show more details about what’s going on.

animosity22 · February 22, 2023, 10:11pm

This is the strangest thing.

If I add in another host on the line, all 4 run through in the logs.

So I did something like:

        dynamic_dns {
                provider cloudflare {env.CLOUDFLARE_API_TOKEN}
                domains {
                        blah.com home test
                }
        }

add test after home and I get 4 entries.

If I remove test from the same Caddyfile only, I get only the IPV4.

        dynamic_dns {
                provider cloudflare {env.CLOUDFLARE_API_TOKEN}
                domains {
                        blah.com test
                }
        }

Not quite sure what’s so different between those two configs as they are very simple.

animosity22 · February 22, 2023, 10:34pm

And if I change it to a full name, it works, but complains it can’t find a zone.

        dynamic_dns {
                provider cloudflare {env.CLOUDFLARE_API_TOKEN}
                domains {
                        home.blah.com
                }
        }

francislavoie · February 22, 2023, 11:00pm

Ah right, does the domain you care about already have a AAAA record? If not, set an initial one. I think we don’t attempt to set a record if there isn’t one yet.

animosity22 · February 23, 2023, 12:13am

I think I see my confusion.

For some reason my IPV4 always detects as ‘new’ and it updates / logs every time.

My IPV6 only logs when it updates and if I delete the AAAA record, it creates a new one no problem, and logs it:

If I restart the instance again, my IPV4 flags as wrong/new for some reason, updates and the IPV6 doens’t log as it didn’t change.

I was confused on the IPv6 not logging every time like the IPV4 is as it seems to think it changes every time, which it has not.

Is there anything to check on why the IPV4 think it’s different as the IP it updates to is the same one there already?

francislavoie · February 23, 2023, 12:26am

If you enable the debug global option, it should give you more detailed logs about this. Hard to say otherwise.

animosity22 · February 23, 2023, 12:50am

I turned on debug and just see it’s trying to check the IP and just updates with the same:

Feb 22 19:12:40 phoenix caddy[74345]: {"level":"info","ts":1677111160.037191,"logger":"dynamic_dns","msg":"finished updating DNS"}
Feb 22 19:16:20 phoenix caddy[74558]: {"level":"info","ts":1677111380.192732,"logger":"dynamic_dns","msg":"different IP address","new_ip":"98.1.2.3"}
Feb 22 19:16:20 phoenix caddy[74558]: {"level":"info","ts":1677111380.1928189,"logger":"dynamic_dns","msg":"updating DNS record","zone":"blah.us","type":"A","name":"home","value":"98.1.2.3","ttl":0}
Feb 22 19:16:20 phoenix caddy[74558]: {"level":"info","ts":1677111380.6175013,"logger":"dynamic_dns","msg":"finished updating DNS"}
Feb 22 19:19:22 phoenix caddy[74838]: {"level":"info","ts":1677111562.510977,"logger":"dynamic_dns","msg":"different IP address","new_ip":"98.1.2.3"}
Feb 22 19:19:22 phoenix caddy[74838]: {"level":"info","ts":1677111562.5110557,"logger":"dynamic_dns","msg":"updating DNS record","zone":"blah.us","type":"A","name":"home","value":"98.1.2.3","ttl":0}
Feb 22 19:19:22 phoenix caddy[74838]: {"level":"info","ts":1677111562.926998,"logger":"dynamic_dns","msg":"finished updating DNS"}
Feb 22 19:39:29 phoenix caddy[77470]: {"level":"debug","ts":1677112769.3559759,"logger":"dynamic_dns","msg":"beginning IP address check"}
Feb 22 19:39:30 phoenix caddy[77470]: {"level":"info","ts":1677112770.4662554,"logger":"dynamic_dns","msg":"different IP address","new_ip":"98.1.2.3"}
Feb 22 19:39:30 phoenix caddy[77470]: {"level":"info","ts":1677112770.466342,"logger":"dynamic_dns","msg":"updating DNS record","zone":"blah.us","type":"A","name":"home","value":"98.1.2.3","ttl":0}
Feb 22 19:39:30 phoenix caddy[77470]: {"level":"info","ts":1677112770.907853,"logger":"dynamic_dns","msg":"finished updating DNS"}
Feb 22 19:46:46 phoenix caddy[77942]: {"level":"debug","ts":1677113206.384899,"logger":"dynamic_dns","msg":"beginning IP address check"}
Feb 22 19:46:47 phoenix caddy[77942]: {"level":"info","ts":1677113207.2474804,"logger":"dynamic_dns","msg":"different IP address","new_ip":"98.1.2.3"}
Feb 22 19:46:47 phoenix caddy[77942]: {"level":"info","ts":1677113207.24756,"logger":"dynamic_dns","msg":"updating DNS record","zone":"blah.us","type":"A","name":"home","value":"98.1.2.3","ttl":0}
Feb 22 19:46:47 phoenix caddy[77942]: {"level":"info","ts":1677113207.6931887,"logger":"dynamic_dns","msg":"finished updating DNS"}

adjust the domain/IP to generic items as I’m not sure where to figure out more logging on the checking IP part as that seems to be the only line printed.

francislavoie · February 23, 2023, 8:25am

Huh, that’s a lot less logging than I’d expect to see. I thought we had a lot more logs in there. I’d expect it to at least say which IP source it used, what the old IP was if different, etc.

There might be resolver problems causing Caddy to see the current IP address incorrectly. Maybe the upnp source is doing the wrong thing? Not sure.

I’ll try to make a pull request to add a bunch more logging soon.

francislavoie · February 23, 2023, 10:33am

Alright, opened a PR to improve logging, and fix a couple issues.

github.com/mholt/caddy-dynamicdns

Increased debug logging, refactor IP sources

mholt:master ← francislavoie:increased-logging

opened 10:11AM - 23 Feb 23 UTC

francislavoie

+327 -961

As per https://caddy.community/t/dynamic-dns-ipv6/19053/8, there's a distinct la…ck of debug logging to be able to understand what's going wrong. Also, I rewrote the HTTP source because it had duplicated code branches and I think it would give up on trying IPv6 if a particular endpoint returned a good IPv4 but not IPv6, because of the `if len(ips) > 0` condition. Looping over the endpoints twice makes the IP versions not dependent on eachother at all, so it should be more reliable that way.

Try building with that PR like this:

--with github.com/mholt/caddy-dynamicdns=github.com/francislavoie/caddy-dynamicdns@86f743b5a

animosity22 · February 23, 2023, 12:00pm

Ah, there we go. It’s seeing the IPV6 as the IPV4 address:

Feb 23 06:56:07 phoenix caddy[112234]: {"level":"debug","ts":1677153367.3901315,"logger":"dynamic_dns","msg":"beginning IP address check"}
Feb 23 06:56:09 phoenix caddy[112234]: {"level":"debug","ts":1677153369.1675022,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup","type":"IPv4","endpoint":"https://api64.ipify.org","ip":"98.1.2.3"}
Feb 23 06:56:25 phoenix caddy[112234]: {"level":"debug","ts":1677153385.6254618,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup failed","type":"IPv6","endpoint":"https://api64.ipify.org","error":"Get \"https://api64.ipify.org\": net/http: TLS handshake timeout"}
Feb 23 06:56:35 phoenix caddy[112234]: {"level":"debug","ts":1677153395.6336257,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup failed","type":"IPv6","endpoint":"https://myip.addr.space","error":"Get \"https://myip.addr.space\": dial tcp6 [2a01:4f9:3b:5126:1::189]:443: i/o timeout"}
Feb 23 06:56:35 phoenix caddy[112234]: {"level":"debug","ts":1677153395.796658,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup failed","type":"IPv6","endpoint":"https://ifconfig.me","error":"Get \"https://ifconfig.me\": dial tcp6: lookup ifconfig.me on 192.168.1.25:53: no such host"}
Feb 23 06:56:35 phoenix caddy[112234]: {"level":"debug","ts":1677153395.8699238,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup","type":"IPv6","endpoint":"https://icanhazip.com","ip":"2600:4040:7aed:c000:6662:66ff:ab12:1234"}
Feb 23 06:56:35 phoenix caddy[112234]: {"level":"info","ts":1677153395.8700247,"logger":"dynamic_dns","msg":"different IP address","new_ip":"98.1.2.3","old_ips":["2600:4040:7aed:c000:6662:66ff:ab12:1234"]}
Feb 23 06:56:35 phoenix caddy[112234]: {"level":"info","ts":1677153395.8700612,"logger":"dynamic_dns","msg":"updating DNS record","zone":"blah.com","type":"A","name":"home","value":"98.1.2.3","ttl":0}
Feb 23 06:56:36 phoenix caddy[112234]: {"level":"info","ts":1677153396.2374184,"logger":"dynamic_dns","msg":"finished updating DNS","current_ips":["98.1.2.3","2600:4040:7aed:c000:6662:66ff:ab12:1234"]}

francislavoie · February 23, 2023, 12:06pm

If you’re referring to old_ips, it’s normal for that to show both the IPv4 and IPv6. That’s an array of all the known IPs in DNS prior to this procedure

In this case it only knew about a prior IPv6 for some reason. It might be “aware” of the IPv4 on the next interval. The interval is 30 min by default, you could shorten it temporarily to like 2 minutes and reload Caddy, see what appears in the logs on the next try.

animosity22 · February 23, 2023, 12:14pm

I turned down the interval to 1 minute and let it go, but my question was more so the ‘old_ips’ only has the IPv6 without the IPV4 and the ‘current_ips’ has both the IPV4 and the IPV6 in the debug out.

If the IPV4 is missing from the logs in old_ips, it updates it just the first time so I’d surmise something is going wrong in that very first check as the subsequent ones work.

1 minute internal log:

Feb 23 07:09:43 phoenix caddy[2880]: {"level":"debug","ts":1677154183.1979156,"logger":"dynamic_dns","msg":"beginning IP address check"}
Feb 23 07:09:44 phoenix caddy[2880]: {"level":"debug","ts":1677154184.077126,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup","type":"IPv4","endpoint":"https://api64.ipify.org","ip":"98.1.2.3"}
Feb 23 07:09:44 phoenix caddy[2880]: {"level":"debug","ts":1677154184.3872108,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup","type":"IPv6","endpoint":"https://api64.ipify.org","ip":"2600:4040:7aed:c000:6662:66ff:ab12:1234"}
Feb 23 07:09:44 phoenix caddy[2880]: {"level":"info","ts":1677154184.3872962,"logger":"dynamic_dns","msg":"different IP address","new_ip":"98.1.2.3","old_ips":["2600:4040:7aed:c000:6662:66ff:ab12:1234"]}
Feb 23 07:09:44 phoenix caddy[2880]: {"level":"info","ts":1677154184.3873358,"logger":"dynamic_dns","msg":"updating DNS record","zone":"blah.com","type":"A","name":"home","value":"98.1.2.3","ttl":0}
Feb 23 07:09:44 phoenix caddy[2880]: {"level":"info","ts":1677154184.7306595,"logger":"dynamic_dns","msg":"finished updating DNS","current_ips":["98.1.2.3","2600:4040:7aed:c000:6662:66ff:ab12:1234"]}
Feb 23 07:10:43 phoenix caddy[2880]: {"level":"debug","ts":1677154243.1987116,"logger":"dynamic_dns","msg":"beginning IP address check"}
Feb 23 07:10:43 phoenix caddy[2880]: {"level":"debug","ts":1677154243.547978,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup","type":"IPv4","endpoint":"https://api64.ipify.org","ip":"98.1.2.3"}
Feb 23 07:10:43 phoenix caddy[2880]: {"level":"debug","ts":1677154243.9142442,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup","type":"IPv6","endpoint":"https://api64.ipify.org","ip":"2600:4040:7aed:c000:6662:66ff:ab12:1234"}
Feb 23 07:10:43 phoenix caddy[2880]: {"level":"debug","ts":1677154243.914321,"logger":"dynamic_dns","msg":"no IP address change; no update needed"}
Feb 23 07:11:43 phoenix caddy[2880]: {"level":"debug","ts":1677154303.1978972,"logger":"dynamic_dns","msg":"beginning IP address check"}
Feb 23 07:11:43 phoenix caddy[2880]: {"level":"debug","ts":1677154303.5212939,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup","type":"IPv4","endpoint":"https://api64.ipify.org","ip":"98.1.2.3"}
Feb 23 07:11:43 phoenix caddy[2880]: {"level":"debug","ts":1677154303.8665137,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup","type":"IPv6","endpoint":"https://api64.ipify.org","ip":"2600:4040:7aed:c000:6662:66ff:ab12:1234"}
Feb 23 07:11:43 phoenix caddy[2880]: {"level":"debug","ts":1677154303.8665922,"logger":"dynamic_dns","msg":"no IP address change; no update needed"}
Feb 23 07:12:43 phoenix caddy[2880]: {"level":"debug","ts":1677154363.1979027,"logger":"dynamic_dns","msg":"beginning IP address check"}
Feb 23 07:12:43 phoenix caddy[2880]: {"level":"debug","ts":1677154363.5568614,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup","type":"IPv4","endpoint":"https://api64.ipify.org","ip":"98.1.2.3"}
Feb 23 07:12:47 phoenix caddy[2880]: {"level":"debug","ts":1677154367.2295194,"logger":"dynamic_dns.ip_sources.simple_http","msg":"lookup","type":"IPv6","endpoint":"https://api64.ipify.org","ip":"2600:4040:7aed:c000:6662:66ff:ab12:1234"}
Feb 23 07:12:47 phoenix caddy[2880]: {"level":"debug","ts":1677154367.2296069,"logger":"dynamic_dns","msg":"no IP address change; no update needed"}

francislavoie · February 23, 2023, 12:21pm

Oh yeah I see the issue now.

The loop that reads the initial records is a map by the record name only, and not both name and type. So both A and AAAA have the same record name but different types. So one ends up clobbering the other, both are not kept.

But that loop is only used to set up the initial state, because Caddy keeps in memory what the records were on the previous run instead of fetching them from the DNS API every time, because that could be expensive if the DNS API has rate limits or is costed per API call.

That whole part needs a rewrite I think. I’ll look into that at some point. There’s also this bug Bug: Will not update when one domain is outdated but another is up-to-date · Issue #30 · mholt/caddy-dynamicdns · GitHub which is semi-related as well which should be addressed at the same time.

animosity22 · February 23, 2023, 12:27pm

Awesome. Thanks for validating as in the grand scheme of things, it’s a very minor issue as I just wanted to make sure I was not doing anything incorrect or had some other issue in my setup.

Appreciate the patience and help finding it!