dynamic DNS - 1/3 not correctly set at boot



  • When a power outage occurs, my IP address usually changes. Today, that happened.

    At Services | Dynamic DNS | Dynamic DNS Clients I have three entries. Two of them were correct. One was not.

    • DynDNS - wrong
    • HE.net - correct
    • OpenDNS - correct

    This always seems to be the case after a power failure.

    When I click on Edit Service for DynDNS, and then click on Save & Force Update, the update occurs as expected.

    I don't know why this does not get set correctly on boot, but the other two do.

    I also have three entries under RFC 2136 Clients, all of which are incorrect. These interact with hosts on the local LAN. Why they don't get updated, I don't know. uptime is now about 4 hours.

    While reading the docs, I looked at Services | Dynamic DNS | Check IP Services and noticed the default service, http://checkip.dyndns.org, was enabled. When I visit that URL, the IP address I get is nowhere close to mine. http://checkip.dyndns.org:8245/ reports the same wonky IP. It's in 173.120/16 whereas I'm in 98/8

    I have no idea if the problem are related or not.

    I see this entry in /etc/crontab:

    1	1	*	*	*	root	/usr/bin/nice -n20 /etc/rc.dyndns.update
    

    Perhaps I need to wait for this to run. if so, that seems ... inconvenient.



  • The RFC 2136 Clients were updated at 1:01 via the cronjob.

    Once a day is insufficient.



  • @dvl said in dynamic DNS - 1/3 not correctly set at boot:

    I don't know why this does not get set correctly on boot, but the other two do.

    Normally, you would tell us why it didn't happen.
    This :
    0_1551169823637_f67b5342-417e-4d6f-be79-2826bd1270d4-image.png

    and the corresponding log lines should contain the answer.

    @dvl said in dynamic DNS - 1/3 not correctly set at boot:

    RFC 2136 Clients, all of which are incorrect. These interact with hosts on the local LAN

    Same thing, and better : look also at the "what happened screen" == the logs lines of the corresponding DNS servers, the ones that operate on nsupdate commands.

    http://checkip.dyndns.org:8245/ and http://checkip.dyndns.org works fine. If they didn't, the impact would be huge.

    @dvl said in dynamic DNS - 1/3 not correctly set at boot:

    Perhaps I need to wait for this to run. if so, that seems ... inconvenient.

    Noop.
    Try :
    0_1551170129711_bde96362-fca9-4f4d-9f5d-f2657f83f927-image.png

    and activate logging first, and check the logs.
    Tell us what happened ;)

    PS : probably something like : your pfSense came up, but upstream WAN connections wasn't ready yet ...



  • @gertjan said in dynamic DNS - 1/3 not correctly set at boot:

    @dvl said in dynamic DNS - 1/3 not correctly set at boot:

    I don't know why this does not get set correctly on boot, but the other two do.

    Normally, you would tell us why it didn't happen.

    A good point.

    I was looking at the GUI log entries, which were at 50 items-displayed. I have bumped that up, and I've since checked /var/log/system.log ... oops.

    This :
    0_1551169823637_f67b5342-417e-4d6f-be79-2826bd1270d4-image.png

    and the corresponding log lines should contain the answer.

    Fortunately, the answers were still in the log, which dates back some 8 days.

    @dvl said in dynamic DNS - 1/3 not correctly set at boot:

    RFC 2136 Clients, all of which are incorrect. These interact with hosts on the local LAN

    Same thing, and better : look also at the "what happened screen" == the logs lines of the corresponding DNS servers, the ones that operate on nsupdate commands.

    http://checkip.dyndns.org:8245/ and http://checkip.dyndns.org works fine. If they didn't, the impact would be huge.

    I'm sure they were working fine for most people. I am often encountering edge cases where they things don't work as expected. My searches before posting also found instances of where folks were not getting expected results.

    That said, I think I now know why I wasn't getting expected results.

    @dvl said in dynamic DNS - 1/3 not correctly set at boot:

    Perhaps I need to wait for this to run. if so, that seems ... inconvenient.

    Noop.
    Try :
    0_1551170129711_bde96362-fca9-4f4d-9f5d-f2657f83f927-image.png

    and activate logging first, and check the logs.

    Yes, I did that with the 1/3 which was wrong. But if I are remote and cannot get in, I cannot click on that. Mostly because you don't know what IP address is in use. This is the situation I am trying to avoid. I hope to find a way for the system to heal itself without waiting for 1:01 to come around.

    Tell us what happened ;)

    PS : probably something like : your pfSense came up, but upstream WAN connections wasn't ready yet ...

    Here is what we find:

    Feb 25 16:55:25 bast php-fpm[335]: /rc.newwanip: rc.newwanip: Info: starting on re1.
    Feb 25 16:55:25 bast php-fpm[335]: /rc.newwanip: rc.newwanip: on (IP address: 98.[redacted]) (interface: WAN[wan]) (real interface: re1).
    

    WAN is up, and has an IP address.

    Feb 25 16:55:56 bast php-fpm[336]: /rc.dyndns.update: Curl error occurred: Could not resolve host: members.dyndns.org
    

    This could not resolve the host. It matches the 1/3 which did not get updated. This was the critical one for me.

    pfSense is running a local BIND instance with upstream Forwarder IPs. The resolver logs have rolled over.

    Feb 25 16:56:02 bast php-fpm[336]: /rc.dyndns.update: phpDynDNS: updating cache file /conf/dyndns_wanhe-net-tunnelbroker'219368'1.cache: 98.[redacted]
    Feb 25 16:56:02 bast php-fpm[336]: /rc.dyndns.update: phpDynDNS (219368): (Success) IP Address Updated Successfully!
    

    My HE.net tunnel DNS entry was configured.

    Feb 25 16:56:06 bast php-fpm[336]: /rc.dyndns.update: phpDynDNS: updating cache file /conf/dyndns_wanopendns'bast'2.cache: 98.[redacted]
    Feb 25 16:56:06 bast php-fpm[336]: /rc.dyndns.update: phpDynDNS (bast): (Success) IP Address Changed Successfully! (98.[redacted])
    

    The OpenDNS account was updated.

    Feb 25 16:56:13 bast php-cgi: notify_monitor.php: Could not send the message to dan@example.org -- Error: Failed to connect to cliff.int.example.org:25 [SMTP: Failed to connect socket: Operation timed out (code: -1, response: )]
    

    This is an internal host, and I bet the server has not come up yet. I have a plan for adjusting the PDU power-on delays to fix this.

    Feb 25 16:56:28 bast php-fpm[336]: /rc.dyndns.update: The command '/usr/local/bin/nsupdate -k /var/etc/nsupdatekey0 -v /var/etc/nsupdatecmds0' returned exit code '1', the output was '; Communication with 10.0.0.53#53 failed: timed out could not reach any name server' 
    Feb 25 16:56:28 bast php-fpm[336]: /rc.dyndns.update: phpDynDNS: ERROR while updating IP Address (A) for services.example.org (98.[redacted])
    Feb 25 16:56:34 bast php-fpm[336]: /rc.dyndns.update: The command '/usr/local/bin/nsupdate -k /var/etc/nsupdatekey1 -v /var/etc/nsupdatecmds1' returned exit code '1', the output was '; Communication with 10.0.0.53#53 failed: operation canceled could not reach any name server' 
    Feb 25 16:56:34 bast php-fpm[336]: /rc.dyndns.update: phpDynDNS: ERROR while updating IP Address (A) for fedex.example.org (98.[redacted])
    Feb 25 16:56:34 bast php-fpm[336]: /rc.dyndns.update: The command '/usr/local/bin/nsupdate -k /var/etc/nsupdatekey2 -v /var/etc/nsupdatecmds2' returned exit code '1', the output was '; Communication with 10.0.0.53#53 failed: operation canceled could not reach any name server' 
    Feb 25 16:56:34 bast php-fpm[336]: /rc.dyndns.update: phpDynDNS: ERROR while updating IP Address (A) for bast.example.org (98.[redacted])
    Feb 25 16:56:43 bast php-cgi: notify_monitor.php: Could not send the message to dan@example.org -- Error: Failed to connect to cliff.int.example.org:25 [SMTP: Failed to connect socket: Operation timed out (code: -1, response: )]
    

    pfSense runs secondary DNS for int.example.org, which is hosted on two internal servers. They weren't up yet I bet. Again, PDU power-on delay settings

    Thank you. I have another mini-project coming up.



  • @dvl said in dynamic DNS - 1/3 not correctly set at boot:

    Curl error occurred: Could not resolve host: members.dyndns.org

    I see the same thing :

    [2.4.4-RELEASE][admin@pfsense.brit-hotel-fumel.net]/root: host members.dyndns.org
    members.dyndns.org is an alias for vip.web1-05-ussnn1.prod.dc.dyndns.com.
    vip.web1-05-ussnn1.prod.dc.dyndns.com has address 162.88.175.12
    [2.4.4-RELEASE][admin@pfsense.brit-hotel-fumel.net]/root: curl 162.88.175.12
    404
    

    I not using any DynDNS paid (?) services - but this URL returns "404" as a text result.
    That's not really a valid IP address.
    You really need "members.dyndns.org" ? The default "checkip.dyndns.org" isn't good enough ?



  • @gertjan said in dynamic DNS - 1/3 not correctly set at boot:

    I not using any DynDNS paid (?) services - but this URL returns "404" as a text result.
    That's not really a valid IP address.
    You really need "members.dyndns.org" ? The default "checkip.dyndns.org" isn't good enough ?

    Good catch. However, I think that tests the wrong URL.

    In my case, the 'Service Type' I have selected at /services_dyndns_edit.php?id=0 is 'DynDNS (dynamic)'.

    This is defined in /etc/inc/services.inc, look for define('DYNDNS_PROVIDER_VALUES'

    In /etc/inc/dyndns.class I find: $server = "https://members.dyndns.org/nic/update";

    That URL works:

    $ curl https://members.dyndns.org/nic/update
    badauth
    

    Thank you



  • @dvl said in dynamic DNS - 1/3 not correctly set at boot:

    However, I think that tests the wrong URL

    The "DynDNS client" build into pfSense uses checkip.dyndns.org because it's special : it should return an nearly empty html page as a reply.
    It should contain a IPv4 address. That's the adress the web server (at checkip.dyndns.org) caught as our WAN IPv4.
    It's has nothing to do with the URL or domain name. Yo could use any test page, as long as it returns the WAN IP as a reply.

    Btw : click on it and see for yourself : checkip.dyndns.org

    Your "members.dyndns.org" page bails out with a "404" as a reply. That's good enough to fail the test. The DynDNS update procedure stops.

    This : https://members.dyndns.org/nic/update (with a lot of parameters which must be valid) is part of the update API @ dyndns.org - and has nothing to do with detecting a WAN IP. User ID, the IPv4 and whatever else should be added (encoded) so you, the DynDNS client, can identify itself.



  • @gertjan said in dynamic DNS - 1/3 not correctly set at boot:

    Your "members.dyndns.org" page bails out with a "404" as a reply. That's good enough to fail the test. The DynDNS update procedure stops.

    You say 'your'. It is not mine. It is built into the pfSense code. It is the page used to update the IP address with my DynDNS provider. It is not the page used to determine the IP address.

    Am I confused about this interpretation of what is going on?



  • @dvl said in dynamic DNS - 1/3 not correctly set at boot:

    Am I confused about this interpretation of what is going on?

    Hummmm.
    I see what you mean .... !

    Feb 25 16:55:56 bast php-fpm[336]: /rc.dyndns.update: Curl error occurred: Could not resolve host: members.dyndns.org
    

    This is probably an error spit out during line 460 - /etc/inc/dyndns.class - suddenly "members.dyndns.org" couldn't be be resolved.
    Or, a small moment just before that point, checkip.dyndns.org resolved very well.

    I guess it's actually just bad timing : the resolver (or forwarder) was being restart at that very moment.



  • Are you sure that checkip.dyndns.org is being invoked at this point or is pfSense acting upon knowing a change has occurred?



  • _Checkip() is called first, and uses the checkip.dyndns.org URL to get the actual WAN IP.
    It's compared with the cached IP.
    If different, in the case of a dyndns.org, htpps://members.dyndns.org&...... is called to set the new WAN IP.
    It's that last call that fails with a "cannot resolve", I guess because at that moment the Resolver was asked to restart for some reason.

    edit : remember : power came just back, processes starting up, like the dyndns house keeping. At boot time, it's not unknown that processes restart more often. Unbound is pretty known for being kicked around a lot.



  • @gertjan For what it's worth, I'm using BIND here.

    In the case of a power-up after a power-failure, what can be done to ensure success on this? I have an idea.

    I am tempted to invoke create a cronjob which will be invoked using the @reboot feature. That script will first sleep for 5 minutes, and then invoke /etc/rc.dyndns.update

    This sleep time is based on:

    • the system booted at Feb 25 16:55:01
    • the 'Could not resolve host' log entry at Feb 25 16:55:56

    This means any failed initial sequence will be fixed 5 minutes later.



  • 👍

    In my early "pfSEnse" days, I also discovered that sometimes my dyndns IP was not updated.
    What I did : I inserted into the /etc/inc/dyndns.class file a sleep(60) timer.
    You solution is much more cleaner !



  • Thanks.

    I try to never modify vendor code, instead preferring to send patches upstream.

    Maintaining your own set of patches is not sustainable for moving targets.

    I just installed the cron package. What is an appropriate place to install my scripts? I'm planning on /usr/local/sbin/fix-dydns-after-reboot.sh



  • Here is the file:

    $ ls -l /usr/local/sbin/fix-dydns-after-reboot.sh
    -rwxr-xr-x  1 root  wheel  138 Feb 28 15:40 /usr/local/sbin/fix-dydns-after-reboot.sh
    
    $ cat /usr/local/sbin/fix-dydns-after-reboot.sh
    #!/bin/sh
    
    # sleep for 5 minutes
    /bin/sleep 300
    
    # invoke the same code as found in the crontab
    /usr/bin/nice -n20 /etc/rc.dyndns.update
    

    What I just found amusing: I ran the job from the command line and wondered why I was not seeing anything in the log files....

    I need to wait 5 minutes.



  • Confirmed, this worked, by viewing: /status_logs.php

    I then added to cron, to run at a soon-to-occur time. That ran fine too.

    I am now confident this will run at @reboot.



  • An interesting popup when trying to delete a cron entry:

    0_1551369702981_Screen Shot 2019-02-28 at 11.00.48 AM.png



  • This is what the resulting cronjob looks like:

    0_1551370121202_Screen Shot 2019-02-28 at 11.02.15 AM.png


Log in to reply