hover-ddns sometimes fails to receive current IP address

Question

hover-ddns sometimes fails to receive current IP address

danabucci opened this issue 5 years ago · 4 comments

I have the systemd timer and service set up. Occasionally the service just fails to get the current external IP address, and tries to use an empty string to update the A record. This results in the record successfully being deleted, but the new record cannot be created since Hover rejects the empty IP address. I have to manually recreate the record using the Hover UI, or run hover-ddns with the manual IP setting and the "force" setting enabled in the config file:

sudo sed -ie 's/force_update: false/force_update: true/' /etc/hover-ddns.yaml
sudo /usr/local/bin/hover-ddns --verbose --config /etc/hover-ddns.yaml --ip-address $(curl -s https://api.ipify.org\?format\=text)

Perhaps this is an issue with the https://api.ipify.org service?

Here is the log, with IP and Hover info censored.

Apr 17 08:46:23 velciter systemd[1]: Started Hover DDNS Updater.
Apr 17 09:02:22 velciter systemd[1]: Starting Hover DDNS Updater...
Apr 17 09:02:22 velciter hover-ddns[8274]: time="2020-04-17T09:02:22-04:00" level=info msg="Getting public IP..."
Apr 17 09:02:22 velciter hover-ddns[8274]: time="2020-04-17T09:02:22-04:00" level=info msg="Received public IP ***.***.***.***"
Apr 17 09:02:22 velciter hover-ddns[8274]: time="2020-04-17T09:02:22-04:00" level=info msg="Resolving current IP..."
Apr 17 09:02:22 velciter hover-ddns[8274]: time="2020-04-17T09:02:22-04:00" level=info msg="Received current IP ***.***.***.***"
Apr 17 09:02:22 velciter hover-ddns[8274]: time="2020-04-17T09:02:22-04:00" level=info msg="DNS entry already up to date - nothing to do."
Apr 17 09:02:22 velciter systemd[1]: hover-ddns.service: Succeeded.
Apr 17 09:02:22 velciter systemd[1]: Started Hover DDNS Updater.
Apr 17 09:18:22 velciter systemd[1]: Starting Hover DDNS Updater...
Apr 17 09:18:22 velciter hover-ddns[8286]: time="2020-04-17T09:18:22-04:00" level=info msg="Getting public IP..."
Apr 17 09:18:24 velciter hover-ddns[8286]: time="2020-04-17T09:18:24-04:00" level=info msg="Received public IP ***.***.***.***"
Apr 17 09:18:24 velciter hover-ddns[8286]: time="2020-04-17T09:18:24-04:00" level=info msg="Resolving current IP..."
Apr 17 09:18:24 velciter hover-ddns[8286]: time="2020-04-17T09:18:24-04:00" level=info msg="Received current IP ***.***.***.***"
Apr 17 09:18:24 velciter hover-ddns[8286]: time="2020-04-17T09:18:24-04:00" level=info msg="DNS entry already up to date - nothing to do."
Apr 17 09:18:24 velciter systemd[1]: hover-ddns.service: Succeeded.
Apr 17 09:18:24 velciter systemd[1]: Started Hover DDNS Updater.
Apr 17 09:34:22 velciter systemd[1]: Starting Hover DDNS Updater...
Apr 17 09:34:22 velciter hover-ddns[8301]: time="2020-04-17T09:34:22-04:00" level=info msg="Getting public IP..."
Apr 17 09:34:25 velciter hover-ddns[8301]: time="2020-04-17T09:34:25-04:00" level=info msg="Received public IP ***.***.***.***"
Apr 17 09:34:25 velciter hover-ddns[8301]: time="2020-04-17T09:34:25-04:00" level=info msg="Resolving current IP..."
Apr 17 09:34:25 velciter hover-ddns[8301]: time="2020-04-17T09:34:25-04:00" level=info msg="Received current IP ***.***.***.***"
Apr 17 09:34:25 velciter hover-ddns[8301]: time="2020-04-17T09:34:25-04:00" level=info msg="DNS entry already up to date - nothing to do."
Apr 17 09:34:25 velciter systemd[1]: hover-ddns.service: Succeeded.
Apr 17 09:34:25 velciter systemd[1]: Started Hover DDNS Updater.
Apr 17 09:50:22 velciter systemd[1]: Starting Hover DDNS Updater...
Apr 17 09:50:22 velciter hover-ddns[8321]: time="2020-04-17T09:50:22-04:00" level=info msg="Getting public IP..."
Apr 17 09:50:23 velciter hover-ddns[8321]: time="2020-04-17T09:50:23-04:00" level=info msg="Received public IP ***.***.***.***"
Apr 17 09:50:23 velciter hover-ddns[8321]: time="2020-04-17T09:50:23-04:00" level=info msg="Resolving current IP..."
Apr 17 09:50:23 velciter hover-ddns[8321]: time="2020-04-17T09:50:23-04:00" level=info msg="Received current IP ***.***.***.***"
Apr 17 09:50:23 velciter hover-ddns[8321]: time="2020-04-17T09:50:23-04:00" level=info msg="DNS entry already up to date - nothing to do."
Apr 17 09:50:23 velciter systemd[1]: hover-ddns.service: Succeeded.
Apr 17 09:50:23 velciter systemd[1]: Started Hover DDNS Updater.
Apr 17 10:06:22 velciter systemd[1]: Starting Hover DDNS Updater...
Apr 17 10:06:22 velciter hover-ddns[8352]: time="2020-04-17T10:06:22-04:00" level=info msg="Getting public IP..."
Apr 17 10:06:22 velciter hover-ddns[8352]: time="2020-04-17T10:06:22-04:00" level=info msg="Received public IP ***.***.***.***"
Apr 17 10:06:22 velciter hover-ddns[8352]: time="2020-04-17T10:06:22-04:00" level=info msg="Resolving current IP..."
Apr 17 10:06:23 velciter hover-ddns[8352]: time="2020-04-17T10:06:23-04:00" level=info msg="Received current IP ***.***.***.***"
Apr 17 10:06:23 velciter hover-ddns[8352]: time="2020-04-17T10:06:23-04:00" level=info msg="DNS entry already up to date - nothing to do."
Apr 17 10:06:23 velciter systemd[1]: hover-ddns.service: Succeeded.
Apr 17 10:06:23 velciter systemd[1]: Started Hover DDNS Updater.
Apr 17 10:22:22 velciter systemd[1]: Starting Hover DDNS Updater...
Apr 17 10:22:22 velciter hover-ddns[8381]: time="2020-04-17T10:22:22-04:00" level=info msg="Getting public IP..."
Apr 17 10:22:52 velciter hover-ddns[8381]: time="2020-04-17T10:22:52-04:00" level=info msg="Received public IP "
Apr 17 10:22:52 velciter hover-ddns[8381]: time="2020-04-17T10:22:52-04:00" level=info msg="Resolving current IP..."
Apr 17 10:22:53 velciter hover-ddns[8381]: time="2020-04-17T10:22:53-04:00" level=info msg="Received current IP ***.***.***.***"
Apr 17 10:22:53 velciter hover-ddns[8381]: time="2020-04-17T10:22:53-04:00" level=info msg="IPs differ - update required..."
Apr 17 10:22:53 velciter hover-ddns[8381]: time="2020-04-17T10:22:53-04:00" level=info msg="Getting Hover auth cookie..."
Apr 17 10:22:53 velciter hover-ddns[8381]: time="2020-04-17T10:22:53-04:00" level=info msg=hover_session
Apr 17 10:22:53 velciter hover-ddns[8381]: time="2020-04-17T10:22:53-04:00" level=info msg="got session cookie"
Apr 17 10:22:54 velciter hover-ddns[8381]: time="2020-04-17T10:22:54-04:00" level=info msg="Found domain ID: **********"
Apr 17 10:22:54 velciter hover-ddns[8381]: time="2020-04-17T10:22:54-04:00" level=info msg="Found existing record ID: ***********"
Apr 17 10:22:54 velciter hover-ddns[8381]: time="2020-04-17T10:22:54-04:00" level=info msg=Deleting...
Apr 17 10:22:54 velciter hover-ddns[8381]: time="2020-04-17T10:22:54-04:00" level=info msg="Creating new record..."
Apr 17 10:22:55 velciter hover-ddns[8381]: time="2020-04-17T10:22:55-04:00" level=error msg="Was not able to create new record: Received status code 422"
Apr 17 10:22:55 velciter systemd[1]: hover-ddns.service: Main process exited, code=exited, status=1/FAILURE
Apr 17 10:22:55 velciter systemd[1]: hover-ddns.service: Failed with result 'exit-code'.
Apr 17 10:22:55 velciter systemd[1]: Failed to start Hover DDNS Updater.

Answer 1 · 2020-04-18T09:15:53.000Z

Thanks for reporting this and providing the log! I think I've run into that issue on my server as well. Would you mind switching to https://github.com/dschanoeh/hover-ddns/releases/tag/v0.1.0 and reporting back if you still see this problem?
In the meantime, I'll see if I can implement an alternate provider and/or a retry.

Cheers,
Jan

Answer 2 · 2020-04-18T18:52:06.000Z

Thanks! I installed the latest version and will monitor for the next few days to see if the same problem occurs.

Answer 3 · 2020-04-28T20:33:39.000Z

@dschanoeh I have had no issues since updating to v0.1.0, and I have since updated to v0.2.0 with no problems as well. I don't think my IP has changed via DHCP since then, but I haven't seen any problems with hover-ddns resolving my external IP in the logs. Looking good.

Answer 4 · 2020-04-29T05:03:42.000Z

Okay thanks. I’ll close this for now. Please open it up again if you see the error.