No pagination handling: New DNS entry on start

[ScrewLooseDan]

I presumed this would update an existing record when an IP address changed. What I'm experiencing is anytime the script is started/restarted, a new entry is made. Is that expected behavior?

First I attempted using Docker and now I'm using it on Ubuntu 18.04.5, both are having same issue.

[skibish]

Hi @ScrewLooseDan,

Thanks for reporting this!

Hm... No, this is definitely not the expected behavior. Which version of the ddns you use?

[ScrewLooseDan]

@skibish - Yeah, I couldn't imagine it was expected behavior, but when it happened in Docker (running on a Synology) and my bare metal Ubuntu machine, I wasn't sure!

$ ddns -v
Version: 3.1.0
CommitHash: 9a907c5f0549648322735a3f9e62aecbfb39e75d

Let me know if there's anything else I can do to help (but I'm not real familiar with Go).

[ScrewLooseDan]

If it helps, this is my .ddns.yml file (redacted private info):

token: "my_token"                          # Digital Ocean token                                                    
domains:                                        # Domains to update                                                                                                         
  - "example.com"                                                                                                                                                          
forceIPV6: false                                 # Use IPv6 address resolve (Default false and force IPv4)                                                                  
records:                                        # Records of the domains to update                                                                                          
  - type: "A"                                   # Record type                                                                                                               
    name: "dyndns"                                 # Record name 

[skibish]

How do you start/restart ddns?

I was able to reproduce this behaviour when I've started two ddns containers simultaneously. I was able to see two A records created in the DO console. And then those two records stay after restarts. But I can't yet reproduce the behaviour of new records created after each restart/start with one ddns...

[ScrewLooseDan]

The docker that I'm using is integrated into Synology (NAS) and it had a web frontend, so I can't be sure of what the exact docker command would be. But, I just ran it manually like below and I'm getting the same behavior. Every time I start the docker, it creates a new entry.

docker run -v /volume1/docker/ddns/ddns.yml:/config/.ddns.yml skibish/ddns -conf-file /config/.ddns.yml

Running it on Ubuntu, I am using the ddns.service file you have on your blog.

[skibish]

Are there any errors in the logs (ddns logs, network, system logs, etc.)?

I try to chase the behaviour and this is the closest what I was able to reproduce up to now:

1. Initial state: there is no records in Digital Ocean for the domain
2. Run script below

#!/bin/bash

for i in {1..4}
do
  docker run -d --rm -v $PWD/test.yml:/test.yml skibish/ddns:3.1.0 -conf-file test.yml &
done

wait

sleep 3

docker rm -f $(docker ps -aq)

3. It creates multiple records because all of them request DO API concurrently and go out of sync creating duplicates.

When I run this script again, nothing changes (no new records added).

I tried to play with number of containers that start at the same time - still the same.

ddns do not delete records currently if found duplicates.

Still looking into this issue and try to replicate.

[ms-zlab]

with the & at the end, you will do this task in background and start it 4 times ...

[skibish]

Hi @ms-zlab,

That's correct for this test. Sequential start/restarts do not show the behavior described. Simultaneous starts do show. But only for start.

[skibish]

I can't reproduce behavior that sequential starts of ddns add new records. I suspect that there are fast restarts or network lag somewhere which lead to this behavior.

[skibish]

Hi @ScrewLooseDan ,

Don't know if issue resolved or not, but maybe you wish to give a try to v4 version?

[ScrewLooseDan]

Hi @ScrewLooseDan ,

Don't know if issue resolved or not, but maybe you wish to give a try to v4 version?

I'm sorry for the delayed response. Haven't had much home computer time lately.

I just tried 4.0.0, still produces new records every time ddns is restarted. Again, tried a docker image (on a Synology) and also on a Ubuntu workstation/server. My home IP address hasn't changed lately, so I haven't been able to verify what happens at an update.

I get nothing significant in the logs (from my Ubuntu server, but the Docker ones look similar):

May 30 21:27:38 servername ddns[29648]: time="2021-05-30T21:27:38-04:00" level=debug msg="using the following configuration file: /etc/ddns.yml"
May 30 21:27:38 servername ddns[29648]: time="2021-05-30T21:27:38-04:00" level=debug msg="initializing ip"
May 30 21:27:38 servername ddns[29648]: time="2021-05-30T21:27:38-04:00" level=info msg="current ip is (redacted)"
May 30 21:27:38 servername ddns[29648]: time="2021-05-30T21:27:38-04:00" level=debug msg="syncing dns records"
May 30 21:27:38 servername ddns[29648]: time="2021-05-30T21:27:38-04:00" level=debug msg=done
May 30 21:32:38 servername ddns[29648]: time="2021-05-30T21:32:38-04:00" level=debug msg="checking if ip ((redacted)) has been updated"
May 30 21:37:38 servername ddns[29648]: time="2021-05-30T21:37:38-04:00" level=debug msg="checking if ip ((redacted)) has been updated"
May 30 21:38:50 servername ddns[29648]: time="2021-05-30T21:38:50-04:00" level=debug msg=shutdown
May 30 21:38:55 servername ddns[6886]: time="2021-05-30T21:38:55-04:00" level=debug msg="using the following configuration file: /etc/ddns.yml"
May 30 21:38:55 servername ddns[6886]: time="2021-05-30T21:38:55-04:00" level=debug msg="initializing ip"
May 30 21:38:56 servername ddns[6886]: time="2021-05-30T21:38:56-04:00" level=info msg="current ip is (redacted)"
May 30 21:38:56 servername ddns[6886]: time="2021-05-30T21:38:56-04:00" level=debug msg="syncing dns records"
May 30 21:38:56 servername ddns[6886]: time="2021-05-30T21:38:56-04:00" level=debug msg=done
May 30 21:43:55 servername ddns[6886]: time="2021-05-30T21:43:55-04:00" level=debug msg="checking if ip ((redacted)) has been updated"

I'm really not sure what I am doing different.

[skibish]

Everything is fine! Thanks for coming back :)

Before starting ddns have you removed previous records from Digital Ocean console?

According to logs everything seems okay...

[ScrewLooseDan]

Before starting ddns have you removed previous records from Digital Ocean console?

Perhaps my expectations are what are incorrect here? I have started with no (relevant) records, ddns starts and makes entries as expected. It's when I restart the script that the duplicate entries are created. Anytime the script (or the server) is restarted, I have to remove previous entries?

[skibish]

No, your expectations are correct, you don't need to remove previous entries because there should be no duplicates. I just try to understand where the issue is...

This is how ddns works:

1. You describe in configuration file which records to update when IP is changed (e.g. type A, name myip)
2. You start ddns
3. ddns fetches records from Digital Ocean for specified domain
4. If ddns did not found matching record (by record type and record name) - it creates a new one
5. if found - it updates the IP of the found one

Maybe something with systemd configuration... May I ask you to change your configuration to the following and see if it helps?

[Unit]
Description=DDNS service
After=network.target
StartLimitIntervalSec=0

[Service]
Type=simple
Restart=always
RestartSec=3
User=[REPLACE WITH USER]
ExecStart=/usr/local/bin/ddns -conf-file /home/[REPLACE WITH USER]/ddns.yml

[Install]
WantedBy=multi-user.target

[ScrewLooseDan]

I switched my ddns.service to the one you posted above, but same issue. To be clear, these are the steps I followed:

1. Stopped ddns service
2. Removed the related DNS entries on DO
3. Made config changes to use the suggested configuration (cut and pasted above, replaced username).
4. $ systemctl daemon-reload
5. $ systemctl start ddns.service
6. Waited 2 update intervals (just to ensure it wasn't that)
7. Checked DO and saw only one set of DNS entries.
8. $ systemctl stop ddns.service
9. Checked DO and saw only one set of DNS entries.
10. $ systemctl start ddns.service
11. Checked DO - Two entries

Again, I don't see anything obvious in the log, but here is my logs again:

Jun  1 01:49:47 servername ddns[6886]: time="2021-06-01T01:49:47-04:00" level=debug msg=shutdown
Jun  1 01:52:16 servername ddns[1012]: time="2021-06-01T01:52:16-04:00" level=debug msg="using the following configuration file: /home/(redacted)/ddns.yml"
Jun  1 01:52:16 servername ddns[1012]: time="2021-06-01T01:52:16-04:00" level=debug msg="initializing ip"
Jun  1 01:52:16 servername ddns[1012]: time="2021-06-01T01:52:16-04:00" level=info msg="current ip is (redacted)"
Jun  1 01:52:16 servername ddns[1012]: time="2021-06-01T01:52:16-04:00" level=debug msg="syncing dns records"
Jun  1 01:52:17 servername ddns[1012]: time="2021-06-01T01:52:17-04:00" level=debug msg=done
Jun  1 01:57:16 servername ddns[1012]: time="2021-06-01T01:57:16-04:00" level=debug msg="checking if ip ((redacted)) has been updated"
Jun  1 02:02:16 servername ddns[1012]: time="2021-06-01T02:02:16-04:00" level=debug msg="checking if ip ((redacted)) has been updated"
Jun  1 02:04:02 servername ddns[1012]: time="2021-06-01T02:04:02-04:00" level=debug msg=shutdown
Jun  1 02:04:29 servername ddns[11776]: time="2021-06-01T02:04:29-04:00" level=debug msg="using the following configuration file: /home/(redacted)/ddns.yml"
Jun  1 02:04:29 servername ddns[11776]: time="2021-06-01T02:04:29-04:00" level=debug msg="initializing ip"
Jun  1 02:04:29 servername ddns[11776]: time="2021-06-01T02:04:29-04:00" level=info msg="current ip is (redacted)"
Jun  1 02:04:29 servername ddns[11776]: time="2021-06-01T02:04:29-04:00" level=debug msg="syncing dns records"
Jun  1 02:04:29 servername ddns[11776]: time="2021-06-01T02:04:29-04:00" level=debug msg=done

And, I added a TXT entry and changed the DNS name I was using just to make sure it wasn't causing a problem. Here's my config:

token: "(redacted)"                          # Digital Ocean token
forceIPV6: false                                 # Use IPv6 address resolve (Default false and force IPv4)
domains:
  (redacted).com: 
  # More details about the fields can be found here:
  # https://developers.digitalocean.com/documentation/v2/#create-a-new-domain-record
  - type: "A"
    name: "test1"
  - type: "TXT"
    name: "demo"

FYI - Unrelated to this issue, I typically use After=network-online.target on my system (Ubuntu) as I find it has more success starting services that are dependent on the network on a reboot then using your suggested After=network.target. But, for now I'll use your suggestion to eliminate as many variables as possible.

[skibish]

Thank you for describing use case in detail!

Hhmhmhmhm... There is no proxy, load balancer or cache layer between the Linux box and ethernet?

The only situation that I can imagine right now is that for some reason Digital Ocean API responding with incorrect set of records OR first response was cached in some middleware on first start.

When ddns is started second time it makes request, but cache layer responses back because of a cache hit (GET request, no new parameters in the URL) and ddns assumes that it needs to add new records.

[ScrewLooseDan]

My setup is pretty basic, no HTTP caching - no proxy or LB of any kind. The API makes an HTTP Post, correct? My last example was running on a fairly standard Ubuntu workstation (baremetal on a NUC), that's connected to a Unifi switch, and internet is via a Unifi UDMP -> Verizon ONS. The DNS gets cached as the UDMP uses dnsmasq, but can't imagine the API cares about that.

I'm trying to think how I could demonstrate there is (or isn't) caching. If you can think of a way to capture caching of the API, let me know. Maybe if I do a packet capture, but I presume the API makes HTTPS calls, so that won't be straight forward.

[skibish]

First request is GET.

I think the simplest way to check is just to execute the request against the API from the terminal using something like cURL:

curl --header "Authorization: Bearer <DIGITAL OCEAN TOKEN>" \
https://api.digitalocean.com/v2/domains/<YOUR DOMAIN>/records

1. Delete records in the Digital Ocean console, do a request to this API as shown above, save the response (let's name it A)
2. Add new records in the Digital Ocean console
3. Do a request to this API as shown above and compare current response (B) with the previous one (A)

Response A should not be equal to response B.

You can also execute request with -vvv flag to add some debug information.

With help of dig we could check how the domain is resolving:

dig api.digitalocean.com

Maybe something unexpected will be there, like strange IPs or DNS resolver is unexpected, etc.

[ScrewLooseDan]

Ah ha!!! I believe maybe we found something!

When I did the initial curl, I couldn't find any "A" records listed. Looking at the API document ion, they only return 20 rows by default and then provide a link to the next page.

https://docs.digitalocean.com/reference/api/api-reference/#section/Introduction/Links-and-Pagination

I'm not sure what determines the order, but in my case, my new "A" and TXT records are on the 2nd page of results (noted as "last"). I'm not overly familiar with go language, but taking a quick look at your code, it looks like it makes a default request (which will only return 20 records) and I don't see anything to handle multiple pages.

As they have documented, you can pull a max of 200 records at time like:

curl --header "Authorization: Bearer <DIGITAL OCEAN TOKEN>" \
https://api.digitalocean.com/v2/domains/<YOUR DOMAIN>/records?per_page=200

With that query I get the expected results, and see the "A" records. It's probably rare most people using dynamic IP's have >20 records and EXCEEDINGLY rare that they would have >200 records.

If my code reading is correct, looks like it's line 60 in do.go could maybe changed to: req, err := d.prepareRequest(http.MethodGet, fmt.Sprintf("/domains/%s/records?per_page=200", domain), nil)

[skibish]

Wow, that's a nice find!

Yes, there is no pagination handling there... And this code line is correct one, right:

https://github.com/skibish/ddns/blob/c8aff55cd97be1005c2ba0597cbbdf1b66c77114/do/do.go#L60

Okay, then it is a bug and should be fixed with proper pagination handling.

Thanks a lot, Holmes :)

[ScrewLooseDan]

Just downloadied 4.0.1 and did some validation. No more extra entries!! Wooohoo!

Thank you so much for your time and quick responses on this. I really appreciate it.