1. This site uses cookies. By continuing to use this site, you are agreeing to our use of cookies. Learn More.

dnsmasq periodically restarting

Discussion in 'Tomato Firmware' started by Morac, Apr 13, 2014.

  1. Morac

    Morac Network Guru Member

    I was running tomato-E3000USB-NVRAM60K-1.28.7502.8MIPSR2Toastman-RT-VPN.bin since June 2013 and it worked well. Yesterday I noticed that dnsmasq was terminating and restarting every 30 minutes exactly as described in this thread. I know it wasn't doing this as recently as early last week.

    Comcast did some network reconfiguration and I know there DHCP server went down for awhile last week so it's possible they reconfigured it or something.

    Anyway I decided to upgrade to tomato-E3000USB-NVRAM60K-1.28.7503.7MIPSR2Toastman-RT-VPN.bin with the hopes that the newer dnsmasq would fix the problem. Unfortunately it did not.

    dnsmasq first loaded at 10:05 AM. At that point I noticed that two of my WiFi devices (iPad and iPhone) had duplicate listings in the Device List page: one for the IPV4 lease and one for the IPV6 lease. At around 10:22 AM, I was changing sorting on that page and refreshing it and the IPV6 leases disappeared. I checked the logs and saw:

    Code:
    Apr 13 10:22:45 unknown user.debug init[1]: 182: pptp peerdns disabled
    Apr 13 10:22:45 unknown daemon.info dnsmasq[1011]: exiting on receipt of SIGTERM
    Apr 13 10:22:45 unknown daemon.info dnsmasq[1224]: started, version 2.69test8-78-g6e0290a cachesize 1500
    Apr 13 10:22:45 unknown daemon.info dnsmasq[1224]: compile time options: IPv6 GNU-getopt no-RTC no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset Tomato-helper auth no-DNSSEC
    Apr 13 10:22:45 unknown daemon.info dnsmasq[1224]: asynchronous logging enabled, queue limit is 5 messages
    Apr 13 10:22:45 unknown daemon.info dnsmasq-dhcp[1224]: DHCP, IP range 192.168.1.100 -- 192.168.1.149, lease time 7d
    Apr 13 10:22:45 unknown daemon.info dnsmasq-dhcp[1224]: DHCPv6, IP range ::1 -- ::255.255.255.255, lease time 12h, template for br*
    Apr 13 10:22:45 unknown daemon.info dnsmasq-dhcp[1224]: DHCPv4-derived IPv6 names on br*
    Apr 13 10:22:45 unknown daemon.info dnsmasq-dhcp[1224]: router advertisement on br*
    Apr 13 10:22:45 unknown daemon.info dnsmasq-dhcp[1224]: DHCPv6, IP range x:x:x:2eb::1 -- x:x:x:2eb::ffff:ffff, lease time 12h, constructed for br0
    Apr 13 10:22:45 unknown daemon.info dnsmasq-dhcp[1224]: DHCPv4-derived IPv6 names on x:x:x:2eb::, constructed for br0
    Apr 13 10:22:45 unknown daemon.info dnsmasq-dhcp[1224]: router advertisement on x:x:x:2eb::, constructed for br0
    Apr 13 10:22:45 unknown daemon.info dnsmasq-dhcp[1224]: IPv6 router advertisement enabled
    Apr 13 10:22:45 unknown daemon.info dnsmasq[1224]: reading /etc/resolv.dnsmasq
    Apr 13 10:22:45 unknown daemon.info dnsmasq[1224]: using nameserver 2001:558:feed::1#53
    Apr 13 10:22:45 unknown daemon.info dnsmasq[1224]: using nameserver 2001:558:feed::2#53
    Apr 13 10:22:45 unknown daemon.info dnsmasq[1224]: using nameserver 75.75.75.75#53
    Apr 13 10:22:45 unknown daemon.info dnsmasq[1224]: using nameserver 75.75.76.76#53
    Apr 13 10:22:45 unknown daemon.info dnsmasq[1224]: read /etc/hosts - 3 addresses
    Apr 13 10:22:45 unknown daemon.info dnsmasq[1224]: read /etc/dnsmasq/hosts/hosts - 8 addresses
    Apr 13 10:22:45 unknown daemon.info dnsmasq-dhcp[1224]: read /etc/dnsmasq/dhcp/dhcp-hosts
    
    There was nothing immediately before or after that in the log. Is there some way of figuring out why this is happening? I already tried changing the debugging level to 8 and restarting dnsmasq, but that doesn't do anything.

    Edit:

    It's back to restarting every 30 minutes (x:22 and x:52), but that time doesn't correspond to when I started the router. The only thing I can think of is it's possible there's an external message being sent every 30 minutes. I had an off and on Internet outage yesterday and I don't recall seeing any restarts during the outage times, but unfortunately I restarted the router so I lost yesterday's logs.
     
    Last edited: Apr 13, 2014
    Spyros likes this.
  2. Spyros

    Spyros LI Guru Member

  3. Morac

    Morac Network Guru Member

    I guess I should have mentioned I'm using DHCPv6 with Prefix Delegation and a prefix of 64. I have Accept RA from WAN checked, LAN unchecked and no static DNS.

    I guess I could trouble shoot by disabling ipv6 and see if the problem stops, but that's not particularly useful. I do know it just started out of the blue with no changes to my network configuration or devices so it's got to be external.
     
  4. Spyros

    Spyros LI Guru Member

    If someone outside the router has the ability to stop dmsmasq then we have a serious hole...
     
  5. ryzhov_al

    ryzhov_al Networkin' Nut Member

    Periodically crashes was on other firmwares too.

    There was a bug with CNAME cache which was fixed recently. You may update dnsmasq or apply those fix.
     
  6. Toastman

    Toastman Super Moderator Staff Member Member

    there will be a new release today with latest dnsmasq updates.
     
    Spyros likes this.
  7. Spyros

    Spyros LI Guru Member

    Thanks, already got my e2000 version :p
     
  8. Morac

    Morac Network Guru Member

    I hope that's it, though I find it odd that I've been using a "broken" version of dnsmasq for years and never experienced this reboot every 30 minutes until this past week.
     
  9. Morac

    Morac Network Guru Member

    Yay! Thanks. Glad to see you are still around.
     
  10. Morac

    Morac Network Guru Member

    Actually would a dnsmasq crash generate a SIGTERM in the logs? Wouldn't it just die?
     
  11. mstombs

    mstombs Network Guru Member

    By default Tomato(usb) restarts dnsmasq if it crashes (you can disable in debugging menu) - you will definitely see the restart messages in the logs - but might miss the brief pause in dhcp serviing/dns resolving.
     
  12. Spyros

    Spyros LI Guru Member

    Is this fixed on Toastman release? Shibby 117 doesn't fix it :(
     
  13. koitsu

    koitsu Network Guru Member

    A segfault would not generate a logging message (that includes SIGSEGV and SIGBUS). Your logging messages clearly show something is sending SIGTERM ("standard kill") to one or more daemons, bare minimum dnsmasq. (dnsmasq also happens to be the chattiest)

    What you're seeing is probably what I've described in other threads (where you've commented too): some part of the init/services management code is actually restarting daemons that quite possibly don't need to be restarted. Debugging and tracking this down is extremely tedious given that all the code is in C and there's not, shall I say, "an extremely user-friendly" way to debug it all. Check out this thread (specifically my latter posts, esp. the one in the smaller font) for details on how some (but not all) of it works. Everything is hard-coded.

    My gut feeling is that you might be hitting DHCP renewal time, have some kind of automated cronjob or service job that runs (ex. Access Restriction), or something along those lines which is restarting many daemons periodically. Whether or not it "should" be restarting them all is what may come under debate/discussion, but like I said it's hard to get concise details.

    There is an NVRAM variable that turns on an immense amount of debugging for this kind of stuff, but I forget what it's called (I don't think it shows up in nvram show either, but I forget). Maybe what I'm remembering is debug_logeval=1 but I'm not sure. Maybe it's setting Console log level to something extremely high under Administration / Debugging, again I'm not sure. I'd need to go sift through the source.
     
  14. Grimson

    Grimson Networkin' Nut Member

    I noticed, while using PPPoE, that dnsmasq get's restarted 3 times in a row everytime the connection drops and tomato reconnects to the internet. Now if you have set the connect mode for wan to "Connect On Demand", that could cause a lot of dnsmasq restarts. Or if your provider disconnects you every "x" hours it would have the same effect.

    To even make better guesses you need to post much more informations about the way your internet connection is set up, and a bigger part of the log showing what happened before and after the dnsmasq restarts.

    Edit:
    Dnsmasq also seems to restart everytime the supplied DNS addresses change, so if your connection is using DHCP and your provider rotates the supplied DNS servers it will cause restarts too.
     
  15. mstombs

    mstombs Network Guru Member

    Does the "Out Of Memory" OOM killer send SIGTERM's? It's a core service function with a hard job - but I have seen it hit dnsmasq since its a big ram process which runs with low privilege - but pretty essential for a router! But I agree fix time restarts will be wan dhcp or access restriction issues. dnsmasq shouldn't have to always restart (and lose its cache) but it can only re-read its setup file and take certain actions when running fresh before dropping doen to lower privilege operation.
     
  16. Morac

    Morac Network Guru Member

    What I don't understand is this suddenly started happening out of the blue. I made no changed on my end prior to it starting to do this. If this is something Tomato has always been doing I'd expect I would have always seen it.

    Well that's not 100% true. I did replace the add the OpenVPN that comes with Toastman with the statically linked one created by LanceThePants, but I don't see how switching to a different OpenVPN would cause dnsmasq to be restarted every 30 minutes.

    Also like I said it's not 30 minutes from boot up. When I boot up it occurs after x minutes and then every 30 minutes after that. I have no idea where "x" comes from, but if this was some kind of periodic processing I'd expect it to occur every 30 minutes from boot up.

    My DHCP lease time on the WAN side is 3 days for ipv4 and 12 hours for ipv6. My LAN DHCP lease time is 7 days. I have no cron jobs listed that run every 30 minutes according to cru. I don't know if I have any service jobs, but I don't have access restrictions enable or pretty much anything else. Everything that's enabled has been enabled for many months prior to this problem starting.

    I tried setting the console log level to the highest value and restarting dnsmasq, but I never got any additional detail. I'm not sure when that takes affect though.
     
    Last edited: Apr 16, 2014
  17. Morac

    Morac Network Guru Member

    Okay here's an odd one. I just looked at my log files and the restarts appear to have stopped as of 12:23 AM this morning. I have no idea why the restarts started out of the blue or why they just as suddenly stopped. I still think it's something external (on the WAN side).

    I don't know if this is related or not, but I've been seeing SSH attempts on my router from various ip addresses (a number are Amazon AWS servers). I have SSH set up to only using public/private key so it should be secure.

    Edit:

    I also looked at /var/run and httpd was also restarting since the pid files for both httpd and dnsmasq had the same timestamp. Both are no longer restarting.
     
    Last edited: Apr 16, 2014
  18. CrazyLemon

    CrazyLemon Connected Client Member

    I just checked my /var/run/ and httpd is also restarting like yours with dnsmasq. Mine have never stopped. Still on 30 minutes. So frustrating
     
  19. Spyros

    Spyros LI Guru Member

    There is a pattern in dnsmasq restarting in my case. Every six hours after the initial connection with mh ISP (Wanup) i'm getting a dnsmasq restart. That means that if i connect at 0:00 then dnsmasq will restart at 06:00- 12:00 - 18:00 - 0:00.

    Here is some info i got from my ISP (Forthnet) translated from Greek to English:

    Τhe CPE should support SLAAC (Auto-Configuration) for receiving a WAN/PPP IPv6 address with a /64 prefix and DHCPv6-PD for assigning a /56 IPv6 prefix στο LAN. The received LAN network is what is being used by the user's equipment either with SLAAC or DHCPv6 from the CPE.

    Since March 14th, 2012 LAN IPv6 prefix changed from /64 to /56 so that the end users can have more than one LAN's.

    March 22nd, 2012

    After extensive testing of assigning static IPv6 prefixes per user for a given time period, we decided to increase the time period of IPv6 prefix leasing from one day to one week. That means that if a user logs out and log back again within the week the received IPv6 prefix for the LAN will be the same. We are examining the possibility to give the end users the ability to choose their IPv6 lease time with options from one minute to one month.
     
  20. M_ars

    M_ars Network Guru Member

    Hi Morac,

    did you solve that problem? I think, i have the same or a very similar problem like you.

    My provider turned on ipv6 this week. I'm on dual stack ipv4/ipv6 pppoe with /56 prefix delegation.

    IPv6 is working but every 15 min (x:15 , x:30 , x:45 ...), dnsmasq restarts, if ipv6 and DHCPv6 with PD is turned on. I have accept RA from WAN checked, LAN unchecked, Request PD Only checked and no static DNS. Ipv4 only is no problem at all, working perfectly... :)

    I am running Toastman 510.6 VPN with dnsmasq 2.76 right now. I also testet 509.8 with dnsmasq 2.73 - but no luck. Same Problem, every 15 min a restart of dnsmasq

    Does someone know how to solve this? :)

    --> dnsmasq[972]: exiting on receipt of SIGTERM ?? Why? Who is sending SIGTERM? :confused: :mad:


    Code:
    Dec 10 11:01:38 RT-N16 daemon.info dnsmasq-dhcp[972]: RTR-ADVERT(br0) 2003:xx:xxxx:xxxx::
    Dec 10 11:01:42 RT-N16 user.debug init[1]: 182: pptp peerdns disabled
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq[972]: exiting on receipt of SIGTERM
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq[1525]: started, version 2.73 cachesize 1500
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq[1525]: compile time options: IPv6 GNU-getopt no-RTC no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack ipset Tomato-helper auth no-DNSSEC loop-detect no-inotify
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq[1525]: asynchronous logging enabled, queue limit is 5 messages
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq-dhcp[1525]: DHCP, IP range 10.xx.xx.100 -- 10.xx.xx.149, lease time 1d
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq-dhcp[1525]: DHCPv6, IP range ::1 -- ::255.255.255.255, lease time 12h, template for br*
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq-dhcp[1525]: DHCPv4-derived IPv6 names on br*
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq-dhcp[1525]: router advertisement on br*
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq-dhcp[1525]: DHCPv6, IP range 2003:xx:xxxx:xxxx::1 -- 2003:xx:xxxx:xxxx::ffff:ffff, lease time 12h, constructed for br0
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq-dhcp[1525]: DHCPv4-derived IPv6 names on 2003:xx:xxxx:xxxx::, constructed for br0
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq-dhcp[1525]: router advertisement on 2003:xx:xxxx:xxxx::, constructed for br0
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq-dhcp[1525]: RTR-ADVERT(br0) 2003:xx:xxxx:xxxx::
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq-dhcp[1525]: IPv6 router advertisement enabled
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq[1525]: reading /etc/resolv.dnsmasq
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq[1525]: using nameserver 2003:xxx:x:x000:0:1:0:53#53
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq[1525]: using nameserver 2003:xxx:x:x000:0:1:0:53#53
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq[1525]: using nameserver 217.xxx.xxx.177#53
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq[1525]: using nameserver 217.xxx.xxx.161#53
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq[1525]: read /etc/hosts - 3 addresses
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq[1525]: read /etc/dnsmasq/hosts/hosts - 3 addresses
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq-dhcp[1525]: read /etc/dnsmasq/dhcp/dhcp-hosts
    Dec 10 11:01:42 RT-N16 daemon.info dnsmasq-dhcp[1525]: RTR-ADVERT(br0) 2003:xx:xxxx:xxxx::
     
  21. M_ars

    M_ars Network Guru Member

    i did some more testing with shibby 101 and radvd 1.9.1 --> result: same problem, after 15 min radvd gets restarted

    I have no cron-jobs or access restrictions...

    Can my ISP send sigterm?? :confused:

    Code:
    Dec 11 12:04:32 RT-N16 user.debug dhcp6c-state[808]: 182: pptp peerdns disabled
    Dec 11 12:04:33 RT-N16 user.debug init[1]: 182: pptp peerdns disabled
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq[587]: reading /etc/resolv.dnsmasq
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq[587]: using nameserver 2xx.0.xxx.161#53
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq[587]: using nameserver 2xx.0.xxx.177#53
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq[587]: using nameserver 2003:xxx:x:xxxx:0:1:0:53#53
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq[587]: using nameserver 2003:xxx:x:xxxx:0:1:0:53#53
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq[587]: exiting on receipt of SIGTERM
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq[870]: started, version 2.63 cachesize 1500
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq[870]: compile time options: IPv6 GNU-getopt no-RTC no-DBus no-i18n no-IDN DHCP DHCPv6 no-Lua TFTP no-conntrack
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq[870]: asynchronous logging enabled, queue limit is 5 messages
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq-dhcp[870]: DHCP, IP range 10.xx.xx.xxx -- 10.xx.xx.xxx, lease time 1d
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq[870]: reading /etc/resolv.dnsmasq
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq[870]: using nameserver 2xx.0.xxx.161#53
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq[870]: using nameserver 2xx.0.xxx.177#53
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq[870]: using nameserver 2003:xxx:x:xxxx:0:1:0:53#53
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq[870]: using nameserver 2003:xxx:x:xxxx:0:1:0:53#53
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq[870]: read /etc/hosts - 3 addresses
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq[870]: read /etc/dnsmasq/hosts/hosts - 3 addresses
    Dec 11 12:04:33 RT-N16 daemon.info dnsmasq-dhcp[870]: read /etc/dnsmasq/dhcp/dhcp-hosts
    Dec 11 12:04:33 RT-N16 daemon.err httpd[884]: bind: [2003:xx:xxxx:xxxx:xxxx:xxxx:xxxx:xxx]:80: Cannot assign requested address
    Dec 11 12:04:33 RT-N16 daemon.warn radvd[506]: Exiting, sigterm or sigint received.
    Dec 11 12:04:33 RT-N16 daemon.info radvd[506]: sending stop adverts
    Dec 11 12:04:33 RT-N16 daemon.info radvd[506]: removing /var/run/radvd.pid
    Dec 11 12:04:33 RT-N16 daemon.err radvd[504]: Exiting, privsep_read_loop had readn return 0 bytes
    Dec 11 12:04:33 RT-N16 daemon.info radvd[887]: version 1.9.1 started
    Dec 11 12:04:33 RT-N16 daemon.info pppd[576]: System time change detected.
    Dec 11 12:04:33 RT-N16 daemon.err httpd[896]: bind: [2003:xx:xxxx:xxxx:xxxx:xxxx:xxxx:xxx]:80: Cannot assign requested address
    Dec 11 12:04:59 RT-N16 cron.err crond[485]: time disparity of 24690903 minutes detected
    Dec 11 12:19:32 RT-N16 daemon.warn radvd[894]: Exiting, sigterm or sigint received.
    Dec 11 12:19:32 RT-N16 daemon.info radvd[894]: sending stop adverts
    Dec 11 12:19:32 RT-N16 daemon.info radvd[894]: removing /var/run/radvd.pid
    Dec 11 12:19:32 RT-N16 daemon.info radvd[1064]: version 1.9.1 started
     
  22. M_ars

    M_ars Network Guru Member

    I think i found out where the 15 minutes are comming from.

    There are two ipv6 dhcp-timers, T1(renew) and T2(rebind)

    My provider Telekom Deutschland (Germany) does use T1 = 900 sec (15 min) and T2 = 1440 sec

    Not my trace, but very helpful - someone else with the same provider :)
    [​IMG]

    Other proivders maybe use different values, for example T1 = 1800 sec (30 min) and T2 = 2880 sec

    This could be the reason why some tomato-user have every 15 min or 30 min or 60 min a reconnect (restart of dnsmasq) using DHCPv6 with Prefix Delegation, it depends on the internet service provider settings.

    I think somehow tomato/dhcp uses the T1-Time to restart dnsmasq. (and radvd in older versions) ? Maybe there is a bug? Can someone else with ipv6 DHCPv6 with Prefix Delegation maybe help and or check the log file how often the reconnect happens?
     
    Last edited: Dec 12, 2016
  23. Grimson

    Grimson Networkin' Nut Member

  24. koitsu

    koitsu Network Guru Member

    Thanks, @Grimson -- that's the thread I was trying to find to post here. ;-)

    Has anyone run with nvram set debug_ipv6=1 ? This will run dhcp6c with the -D flag.

    My gut feeling is that one of the processes -- dhcp6c, radvd, or dnsmasq -- is dying off. Not dying as in "it crashed", but dying as in "it's doing something internally" that causes Tomato init to think it needs to restart things. Tomato init (as a supervisor) notices situations like this and ends up shutting down/restarting several processes that are all intertwined.

    Someone needs to start really sitting down examining all of this in detail alongside the C code in release/src/router/rc to try and figure it out. In other words: whoever wants to try and tackle this needs to be able to reproduce the problem locally and have C knowledge and the time/interest to reverse-engineer the Tomato bits.

    I should note that several years ago, a similar problem manifested. The old TomatoUSB forum has a discussion about it. It wasn't pertaining to IPv6, but rather dnsmasq itself, but you'll get the gist of what I'm trying to convey when I say all of this is extremely convoluted (and yes this patch was applied some time ago): http://tomatousb.org/forum/t-260304/timing-bug-when-restarting-dnsmasq-solved-with-patch

    It's all a mess.

    P.S. -- No, I cannot help with this issue, despite my familiarity with Tomato code. I disable IPv6 because it's a travesty, and you couldn't pay me a million USD to enable it.
     
    M_ars and Toastman like this.
  25. Sean B.

    Sean B. LI Guru Member

    My post in the thread Grimson linked. My conclusion may very well be in error, however sense removing rapid-commit from wide-dhcpv6's config I have not had anymore mystery dnsmasq restarts.
     
    M_ars likes this.
  26. M_ars

    M_ars Network Guru Member

    I think you are right - this could be an very easy & effecitve solution :)

    THX for the hint, I will try/test it in the evening

    ==> according to that: "send rapid-commit" is an option, but we dont need to use it. The four-message exchange could prevent the restart of dnsmasq... will try that.
     
  27. Sean B.

    Sean B. LI Guru Member

    You're welcome. Would be great to have someone else try the same solution and confirm/deny it's causing the issue for them as well.

    And correct, it's not a required option to use. The main thing about it is, as the docs show, both client AND server have to be configured to use it. If your ISP's DHCPv6 server does not allow for that option it will not respond with a specific "Reply Message" but instead respond with an Advertisement. Which causes your client to release the lease and request again due to no valid response to renewal. Hence, dnsmasq is restarted under the same circumstance as the lease had expired and a new IP has been issued.

    Watch that you don't get caught by the firmware reinstating the rapid-commit line into dhcp6c.conf when testing. You'll have to make the change and then kill/run dhcp6c + correct CLI options manually.

    Here's the change for the source in case you find this solves the issue in testing, or just want to test using a build. It's patched against Toastman-ARM, but if using a different build/tree it at least shows where/what to change. Pretty simple.

    Code:
     release/src-rt-6.x.4708/router/rc/dhcp.c | 1 -
     1 file changed, 1 deletion(-)
    
    diff --git a/release/src-rt-6.x.4708/router/rc/dhcp.c b/release/src-rt-6.x.4708/router/rc/dhcp.c
    index 37934bd..c532088 100644
    --- a/release/src-rt-6.x.4708/router/rc/dhcp.c
    +++ b/release/src-rt-6.x.4708/router/rc/dhcp.c
    @@ -507,7 +507,6 @@ void start_dhcp6c(void)
             };
             fprintf(f,
                 " send ia-pd 0;\n"
    -            " send rapid-commit;\n"
                 " request domain-name-servers;\n"
                 " script \"/sbin/dhcp6c-state\";\n"
                 "};\n"
     
    Last edited: Dec 13, 2016
    M_ars likes this.
  28. M_ars

    M_ars Network Guru Member

    I agree Sean B., default should be without "send rapid-commit". It can cause some problems if the DHCPv6 server does not support or allow that option.

    I was able to test the change - what i did:
    1. Disconnect the modem for more than 5 min (no power and ADSL) // hint from Sean.B
    2. changed MAC address for WAN port (--> Reboot) // hint from Sean.B
    3. Waiting :) (5 min) // hint from Sean.B
    4. Reboot/start Tomato (with debug_ipv6=1)
    5. kill dhcp6c
    6. rm -f dhcp6c.conf
    7. start dhcp6c without "rapid-commit": dhcp6c -c /tmp/mnt/RouterUSB/temp/dhcp6c.conf -D -T LL ppp0

    dhcp6c.conf at the USB flash-drive:
    Code:
    interface ppp0 {
     send ia-pd 0;
     request domain-name-servers;
     script "/sbin/dhcp6c-state";
    };
    id-assoc pd 0 {
     prefix ::/56 infinity;
     prefix-interface br0 {
      sla-id 0;
      sla-len 8;
            };
    };
    id-assoc na 0 { };
    Result:
    Code:
    daemon.debug dhcp6c[7035]: dhcp6_reset_timer: reset a timer on ppp0, state=RENEW, timeo=0, retrans=10017
    daemon.debug dhcp6c[7035]: client6_send: a new XID (e5eaa9) is generated
    daemon.debug dhcp6c[7035]: copy_option: set client ID (len 10)
    daemon.debug dhcp6c[7035]: copy_option: set server ID (len 10)
    daemon.debug dhcp6c[7035]: copy_option: set elapsed time (len 2)
    daemon.debug dhcp6c[7035]: copy_option: set option request (len 2)
    daemon.debug dhcp6c[7035]: copyout_option: set IA_PD prefix
    daemon.debug dhcp6c[7035]: copyout_option: set IA_PD
    daemon.debug dhcp6c[7035]: client6_send: send renew to ff02::1:2
    daemon.debug dhcp6c[7035]: client6_recv: receive reply from fe80::e6d3:f1ff:fee2:9a00 on ppp0
    daemon.debug dhcp6c[7035]: dhcp6_get_options: get DHCP option server ID, len 10
    daemon.debug dhcp6c[7035]:   DUID: 00:03:00:01:e4:d3:f1:e2:9a:00
    daemon.debug dhcp6c[7035]: dhcp6_get_options: get DHCP option client ID, len 10
    daemon.debug dhcp6c[7035]:   DUID: 00:03:00:01:84:1b:5e:ee:9a:32
    daemon.debug dhcp6c[7035]: dhcp6_get_options: get DHCP option IA_PD, len 41
    daemon.debug dhcp6c[7035]:   IA_PD: ID=0, T1=900, T2=1440
    daemon.debug dhcp6c[7035]: copyin_option: get DHCP option IA_PD prefix, len 25
    daemon.debug dhcp6c[7035]: copyin_option:   IA_PD prefix: 2003:xxxx:xxxx:xxxx::/56 pltime=1800 vltime=14400
    daemon.debug dhcp6c[7035]: dhcp6_get_options: get DHCP option DNS, len 32
    user.debug init[1]: 182: pptp peerdns disabled
    daemon.info dnsmasq[7617]: exiting on receipt of SIGTERM
    ...
    daemon.debug dhcp6c[7035]: client6_script: script "/sbin/dhcp6c-state" terminated
    daemon.debug dhcp6c[7035]: dhcp6_remove_event: removing an event on ppp0, state=RENEW
    daemon.debug dhcp6c[7035]: client6_recvreply: got an expected reply, sleeping.
    
    this still happens every 15 min. RENEW --> REPLY --> Sleeping

    So the change was not successfull in my case but the good thing is that everything was working (restarting) like before. It does not do any damage :)

    After some reading about rapid-commit, i still think we should disable/remove it and use the default four-message exchange (Solicit, Advertise, Request, and Reply)


    Patch for Toastman-RT-AC branch would/could be:
    Code:
    From bc5632e968c05fabe53e7c4b3a122ba5d578cc1b Mon Sep 17 00:00:00 2001
    From: M_ars <M_ars@linksysinfo.org>
    Date: Thu, 15 Dec 2016 18:53:24 +0100
    Subject: [PATCH] dhcp6c.conf - use four-message exchange to configure the
     client
    
    ---
     release/src/router/rc/dhcp.c |    3 ++-
     1 file changed, 2 insertions(+), 1 deletion(-)
    
    diff --git a/release/src/router/rc/dhcp.c b/release/src/router/rc/dhcp.c
    index 37934bd..4a14abc 100644
    --- a/release/src/router/rc/dhcp.c
    +++ b/release/src/router/rc/dhcp.c
    @@ -507,7 +507,8 @@ void start_dhcp6c(void)
             };
             fprintf(f,
                 " send ia-pd 0;\n"
    -            " send rapid-commit;\n"
    +            //" send rapid-commit;\n" // option for two-message exchange (Solicit and Reply) --> faster, but not always allowed/possible!
    +            //Default: use four message exchange (Solicit, Advertice, Request and Reply) to configure the client
                 " request domain-name-servers;\n"
                 " script \"/sbin/dhcp6c-state\";\n"
                 "};\n"
    --
    1.7.9.5
    What do you think Toastman?
    At least it is working for Sean. B :)

    It must be something else... will keep looking. Any suggustions?
     
  29. Toastman

    Toastman Super Moderator Staff Member Member

    It looks interesting, a partial success at any rate. I'll hold back on it to see if any further ideas crop up.
     
  30. Sean B.

    Sean B. LI Guru Member

    I've figured it out. At least the rapid-commit part of it and what issue I was seeing.

    The debug output I posted in the other thread:


    Sep/05/2016 19:16:09: dhcp6_get_options: get DHCP option DNS, len 32
    Sep/05/2016 19:16:09: client6_recvadvert: server ID: 00:01:00:01:17:2b:a5:a9:14:fe:b5:d5:b9:15, pref=255 Sep/05/2016 19:16:09: client6_recvadvert: unexpected advertise
    Sep/05/2016 19:16:09: client6_send: a new XID (33f6bb) is generated

    The RFC behavior for a server which is not rapid-commit enabled is to send a standard advertisement message instead of the expected reply message. the RFC for a client which sends a solicit or renew message containing the rapid commit option is to wait to receive a reply message, but note valid advertisement responses. If after the allowed time for a reply message has passed, it will drop its current configuration and process an advertisement. Quotes from RFC3315v6:

    The rapid commit options is primarily designed for use on a single server ( subnet ) network, or one where response authority is otherwise segmented between servers. Comcast runs multiple servers that all reply and advertise on the same network. Watching the WAN with Wireshark show consistent advertisements from many different server ID's. When used on a multi-server network at the scale such as Comcast, enabling rapid-commit would result in a massive waste of IP's and prefixes:

    For me, the lease time assigned is 4 days.

    @Toastman : My 2 cents are that there's no benefit to having rapid-commit hard-coded. The reduction in message traffic is minute, especially when compared to the extra traffic caused when rapid-commit is not supported on the server. It may not be the cause for all cases of excessive dnsmasq restarts, but it seems to only serve as a possible source of issue rather than any gain.
     
    Last edited: Dec 16, 2016
    Toastman and M_ars like this.
  31. Sean B.

    Sean B. LI Guru Member

    I believe what may have ultimately fixed the dnsmasq restart issue ( for me ) was a code change I had forgot about. At the same time I removed rapid-commit ( as I knew it was either of no benefit or a cause of an issue ) I also changed the code to dhcp6c-state which is the script that dhcp6c runs when a change occurs. The change was implemented as a "fail safe" so to speak in case removing rapid-commit, while removing one issue, may not be the source of the excessive dnsmasq restarts. It encloses the restarting of dnsmasq, httpd, and the changing of the IPv6 router address in NVRAM behind a conditional comparing the current LAN interface IPv6 address ( of which dhcp6c changes when a lease is obtained or lost ) to the IPv6 address currently stored in NVRAM. If the addresses are different the script is run in its entirety. If the addresses are the same, the script bypasses these functions and only runs updating of received DNS servers in case these are now different. And sense dnsmasq actively poles for these changes, a restart is not required. I also added a call to set_host_domain_name(); if an address change has been confirmed, this fixes the issue of the router hostname->IPv6 IP not being updated in /etc/hosts. The changes consists of:

    Code:
     Toastman-ARM
    
    diff --git a/release/src-rt-6.x.4708/router/rc/dhcp.c b/release/src-rt-6.x.4708/router/rc/dhcp.c
    index 37934bd..fc1021a 100644
    --- a/release/src-rt-6.x.4708/router/rc/dhcp.c
    +++ b/release/src-rt-6.x.4708/router/rc/dhcp.c
    @@ -436,6 +436,8 @@ void stop_dhcpc(void)
     int dhcp6c_state_main(int argc, char **argv)
     {
         char prefix[INET6_ADDRSTRLEN];
    +    const char *lanif;
    +    lanif = getifaddr(nvram_safe_get("lan_ifname"), AF_INET6, 0);
         struct in6_addr addr;
         int i, r;
     
    @@ -443,19 +445,24 @@ int dhcp6c_state_main(int argc, char **argv)
     
         if (!wait_action_idle(10)) return 1;
     
    -    nvram_set("ipv6_rtr_addr", getifaddr(nvram_safe_get("lan_ifname"), AF_INET6, 0));
    -
    -    // extract prefix from configured IPv6 address
    -    if (inet_pton(AF_INET6, nvram_safe_get("ipv6_rtr_addr"), &addr) > 0) {
    -        r = nvram_get_int("ipv6_prefix_length") ? : 64;
    -        for (r = 128 - r, i = 15; r > 0; r -= 8) {
    -            if (r >= 8)
    -                addr.s6_addr[i--] = 0;
    -            else
    -                addr.s6_addr[i--] &= (0xff << r);
    +    if (!nvram_match("ipv6_rtr_addr", lanif)) {
    +        nvram_set("ipv6_rtr_addr", lanif);
    +        // extract prefix from configured IPv6 address
    +        if (inet_pton(AF_INET6, nvram_safe_get("ipv6_rtr_addr"), &addr) > 0) {
    +            r = nvram_get_int("ipv6_prefix_length") ? : 64;
    +            for (r = 128 - r, i = 15; r > 0; r -= 8) {
    +                if (r >= 8)
    +                    addr.s6_addr[i--] = 0;
    +                else
    +                    addr.s6_addr[i--] &= (0xff << r);
    +            }
    +            inet_ntop(AF_INET6, &addr, prefix, sizeof(prefix));
    +            nvram_set("ipv6_prefix", prefix);
             }
    -        inet_ntop(AF_INET6, &addr, prefix, sizeof(prefix));
    -        nvram_set("ipv6_prefix", prefix);
    +        // (re)start dnsmasq and httpd
    +        set_host_domain_name();
    +        start_dnsmasq();
    +        start_httpd();
         }
     
         if (env2 nv("new_domain_name_servers", "ipv6_get_dns")) {
    @@ -463,10 +470,6 @@ int dhcp6c_state_main(int argc, char **a
     //        start_dnsmasq();    // (re)start KDB don't do twice!
        }
    
    -    // (re)start dnsmasq and httpd
    -    start_dnsmasq();
    -    start_httpd();
    -
        TRACE_PT("ipv6_get_dns=%s\n", nvram_safe_get("ipv6_get_dns"));
        TRACE_PT("end\n");
        return 0;
    I have compiled a MIPS build for @M_ars with these changes implemented. If they show to remedy his issues, combined with myself having been running these changes for several months without any adverse or unintended issues arising, they may be worth consideration for implementation. As users encountering excessive dnsmasq restarts when IPv6 is enabled does not appear to be a rare or isolated occurrence. The only part of these changes I cannot give my honest confidence in is their implementation for a delegated prefix smaller than 64 allowing for subnets as I am not able to test that scenario. I "believe" there would be no issues encountered, as dhcp6c assigns IPs from the prefix obtained to all respective subnets/LAN interfaces in the same call to dhcp6c-state. Therefor any changes ( or filtered erroneous changes ) to the prefix and any subnets/interfaces should be encompassed in each call to dhcp6c-state as well.

    I believe the concept of this change came from a topic I started several months ago. And results attributed to the discussion/combined efforts between myself, @koitsu and @Grimson.
     
    Last edited: Dec 16, 2016
  32. Elfew

    Elfew Network Guru Member

    +1, good job!
     
  33. koitsu

    koitsu Network Guru Member

    This is extremely bad form. The assignment needs to be moved out of where the variables are declared (this is commonly referred to as the "top of the scope block") and down into the area code prior to where it's used. Separation of the two is done with a blank line. GCC allows for bad code like this but it's still violating existing conventions (of both ANSI and existing code style): Covered: http://stackoverflow.com/questions/288441/variable-declaration-placement-in-c

    In other words -- good:

    Code:
     int dhcp6c_state_main(int argc, char **argv)
     {
        char prefix[INET6_ADDRSTRLEN];
        const char *lanif;
        struct in6_addr addr;
        int i, r;
    
        ...
    
        lanif = getifaddr(nvram_safe_get("lan_ifname"), AF_INET6, 0);
    
    Also good/OK as long as the variable is used throughout the program, i.e. there's no short-circuit returns or ways for the function to exit prior to said variables' use (if there is, then the above is better form):

    Code:
     int dhcp6c_state_main(int argc, char **argv)
     {
        char prefix[INET6_ADDRSTRLEN];
        const char *lanif = getifaddr(nvram_safe_get("lan_ifname"), AF_INET6, 0);
        struct in6_addr addr;
        int i, r;
    
        ...
    
    Bad:

    Code:
     int dhcp6c_state_main(int argc, char **argv)
     {
        char prefix[INET6_ADDRSTRLEN];
        const char *lanif;
        lanif = getifaddr(nvram_safe_get("lan_ifname"), AF_INET6, 0);
        struct in6_addr addr;
        int i, r;
    
        ...
    
    And if you can't decide what's appropriate? Ask someone. :) But a good fallback is: when working on open-source projects, ALWAYS stick with existing code style/convention. Mixed-used conventions and syntaxes within an OSS project are the sign of bad quality. Yes, this even means things like: if the existing code uses hard tabs, then your code too should use hard tabs; if the existing code uses 4-space indentations (vs. 8-space), then your code too should use 4 spaces. Etc...
     
  34. Sean B.

    Sean B. LI Guru Member

    So, for the testing/verification stage that it's currently in.. it's acceptable, and would require minor format changes if considered a solution on a wider scale?
     
  35. M_ars

    M_ars Network Guru Member

    did not work, restart happens still --> next attempt with some changes :)
     
  36. koitsu

    koitsu Network Guru Member

    I can't comment on the actual solution itself (I don't use/refuse to use IPv6). In this case, I can only comment on the syntactical aspect of the code. All you have to do is move
    lanif = getifaddr(nvram_safe_get("lan_ifname"), AF_INET6, 0); down to where it's about to be used.
     
  37. Sean B.

    Sean B. LI Guru Member

    Roger that. Thanks!
     
  38. Sean B.

    Sean B. LI Guru Member

    As stated in message, the code wasn't complete. I missed removing the lines for dnsmasq restart when dns servers are received while I was transferring my changes from ARM to MIPS. Proper build is compiling now.
     
    M_ars likes this.
  39. M_ars

    M_ars Network Guru Member

    It is WORKING now :)
    The if-condition to check if there is an change of the ip/prefix is working
    Code:
    if (!nvram_match("ipv6_rtr_addr", lanif)) { ... code ... }
    RENEW (check ip... if()) --> REPLY --> Sleeping --> RENEW (check ip... if()) --> REPLY --> Sleeping ...

    Test-Results:
    I checked one subnet with /64 prefix and also with /56 prefix and 3 vlans (see log)
    --> everything is working, all subnets have full ipv6 connection
    --> no restart of dnsmasq (after the renew time T1 = 900 sec) if there is no change at all

    Code:
    Dec 17 12:54:53 RT-N16 daemon.info dnsmasq-dhcp[871]: DHCP, IP range 10.xx.xx.2 -- 10.xx.xx.254, lease time 1d
    Dec 17 12:54:53 RT-N16 daemon.info dnsmasq-dhcp[871]: DHCP, IP range 10.xx.xx.2 -- 10.xx.xx.254, lease time 1d
    Dec 17 12:54:53 RT-N16 daemon.info dnsmasq-dhcp[871]: DHCP, IP range 10.xx.xx.100 -- 10.xx.xx.149, lease time 1d
    Dec 17 12:54:53 RT-N16 daemon.info dnsmasq-dhcp[871]: DHCPv6, IP range ::1 -- ::255.255.255.255, lease time 12h, template for br*
    Dec 17 12:54:53 RT-N16 daemon.info dnsmasq-dhcp[871]: DHCPv4-derived IPv6 names on br*
    Dec 17 12:54:53 RT-N16 daemon.info dnsmasq-dhcp[871]: router advertisement on br*
    Dec 17 12:54:53 RT-N16 daemon.info dnsmasq-dhcp[871]: DHCPv6, IP range 2003:xxxx:xxxx:bb00::1 -- 2003:xxxx:xxxx:bb00::ffff:ffff, lease time 12h, constructed for br0
    Dec 17 12:54:53 RT-N16 daemon.info dnsmasq-dhcp[871]: DHCPv4-derived IPv6 names on 2003:xxxx:xxxx:bb00::, constructed for br0
    Dec 17 12:54:53 RT-N16 daemon.info dnsmasq-dhcp[871]: router advertisement on 2003:xxxx:xxxx:bb00::, constructed for br0
    Dec 17 12:54:53 RT-N16 daemon.info dnsmasq-dhcp[871]: DHCPv6, IP range 2003:xxxx:xxxx:bb01::1 -- 2003:xxxx:xxxx:bb01::ffff:ffff, lease time 12h, constructed for br1
    Dec 17 12:54:53 RT-N16 daemon.info dnsmasq-dhcp[871]: DHCPv4-derived IPv6 names on 2003:xxxx:xxxx:bb01::, constructed for br1
    Dec 17 12:54:53 RT-N16 daemon.info dnsmasq-dhcp[871]: router advertisement on 2003:xxxx:xxxx:bb01::, constructed for br1
    Dec 17 12:54:53 RT-N16 daemon.info dnsmasq-dhcp[871]: DHCPv6, IP range 2003:xxxx:xxxx:bb02::1 -- 2003:xxxx:xxxx:bb02::ffff:ffff, lease time 12h, constructed for br2
    Dec 17 12:54:53 RT-N16 daemon.info dnsmasq-dhcp[871]: DHCPv4-derived IPv6 names on 2003:xxxx:xxxx:bb02::, constructed for br2
    Dec 17 12:54:53 RT-N16 daemon.info dnsmasq-dhcp[871]: router advertisement on 2003:xxxx:xxxx:bb02::, constructed for br2
    Dec 17 12:54:53 RT-N16 daemon.info dnsmasq-dhcp[871]: IPv6 router advertisement enabled
    ...
    ...
    ...
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: ia_timo: IA timeout for PD-0, state=ACTIVE
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_reset_timer: reset a timer on ppp0, state=RENEW, timeo=0, retrans=9584
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: client6_send: a new XID (d6ead) is generated
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: copy_option: set client ID (len 10)
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: copy_option: set server ID (len 10)
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: copy_option: set elapsed time (len 2)
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: copy_option: set option request (len 2)
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: copyout_option: set IA_PD prefix
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: copyout_option: set IA_PD
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: client6_send: send renew to ff02::1:2
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: client6_recv: receive reply from fe80::e6d3:f1ff:fee2:9a00 on ppp0
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_get_options: get DHCP option server ID, len 10
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]:   DUID: 00:03:00:01:e4:d3:f1:e2:9a:00
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_get_options: get DHCP option client ID, len 10
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]:   DUID: 00:03:00:01:bc:ae:c5:c3:c3:8d
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_get_options: get DHCP option IA_PD, len 41
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]:   IA_PD: ID=0, T1=900, T2=1440
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: copyin_option: get DHCP option IA_PD prefix, len 25
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: copyin_option:   IA_PD prefix: 2003:xxxx:xxxx:bb00::/56 pltime=1800 vltime=14400
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_get_options: get DHCP option DNS, len 32
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: client6_script: script "/sbin/dhcp6c-state" terminated
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_remove_event: removing an event on ppp0, state=RENEW
    Dec 17 13:39:52 RT-N16 daemon.debug dhcp6c[741]: client6_recvreply: got an expected reply, sleeping.
    Dec 17 13:40:09 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br2) 2003:xxxx:xxxx:bb02::
    Dec 17 13:40:54 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br0) 2003:xxxx:xxxx:bb00::
    Dec 17 13:44:45 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br1) 2003:xxxx:xxxx:bb01::
    Dec 17 13:48:54 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br0) 2003:xxxx:xxxx:bb00::
    Dec 17 13:49:16 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br2) 2003:xxxx:xxxx:bb02::
    Dec 17 13:53:49 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br1) 2003:xxxx:xxxx:bb01::
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: ia_timo: IA timeout for PD-0, state=ACTIVE
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_reset_timer: reset a timer on ppp0, state=RENEW, timeo=0, retrans=10767
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: client6_send: a new XID (25a00f) is generated
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: copy_option: set client ID (len 10)
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: copy_option: set server ID (len 10)
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: copy_option: set elapsed time (len 2)
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: copy_option: set option request (len 2)
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: copyout_option: set IA_PD prefix
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: copyout_option: set IA_PD
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: client6_send: send renew to ff02::1:2
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: client6_recv: receive reply from fe80::e6d3:f1ff:fee2:9a00 on ppp0
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_get_options: get DHCP option server ID, len 10
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]:   DUID: 00:03:00:01:e4:d3:f1:e2:9a:00
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_get_options: get DHCP option client ID, len 10
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]:   DUID: 00:03:00:01:bc:ae:c5:c3:c3:8d
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_get_options: get DHCP option IA_PD, len 41
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]:   IA_PD: ID=0, T1=900, T2=1440
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: copyin_option: get DHCP option IA_PD prefix, len 25
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: copyin_option:   IA_PD prefix: 2003:xxxx:xxxx:bb00::/56 pltime=1800 vltime=14400
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_get_options: get DHCP option DNS, len 32
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: info_printf: nameserver[0] 2003:180:2:9000:0:1:0:53
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: info_printf: nameserver[1] 2003:180:2:7000:0:1:0:53
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: get_ia: update an IA: PD-0
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: update_prefix: update a prefix 2003:xxxx:xxxx:bb00::/56 pltime=1800, vltime=14400
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: client6_recvreply: executes /sbin/dhcp6c-state
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: client6_script: script "/sbin/dhcp6c-state" terminated
    Dec 17 13:54:52 RT-N16 daemon.debug dhcp6c[741]: client6_recvreply: got an expected reply, sleeping.
    Dec 17 13:54:58 RT-N16 daemon.info dnsmasq-dhcp[871]: DHCPRENEW(br0) 00:03:00:01:00:11:32:3c:05:8f
    Dec 17 13:54:58 RT-N16 daemon.info dnsmasq-dhcp[871]: DHCPREPLY(br0) 2003:xxxx:xxxx:bb00::ebc9:1c9c 00:03:00:01:00:xx:xx:xx:xx:8f NASHDD
    Dec 17 13:56:44 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br0) 2003:xxxx:xxxx:bb00::
    Dec 17 13:57:55 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br2) 2003:xxxx:xxxx:bb02::
    Dec 17 14:02:57 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br1) 2003:xxxx:xxxx:bb01::
    Dec 17 14:05:21 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br0) 2003:xxxx:xxxx:bb00::
    Dec 17 14:05:31 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br2) 2003:xxxx:xxxx:bb02::
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: ia_timo: IA timeout for PD-0, state=ACTIVE
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_reset_timer: reset a timer on ppp0, state=RENEW, timeo=0, retrans=9531
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: client6_send: a new XID (88b360) is generated
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: copy_option: set client ID (len 10)
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: copy_option: set server ID (len 10)
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: copy_option: set elapsed time (len 2)
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: copy_option: set option request (len 2)
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: copyout_option: set IA_PD prefix
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: copyout_option: set IA_PD
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: client6_send: send renew to ff02::1:2
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: client6_recv: receive reply from fe80::e6d3:f1ff:fee2:9a00 on ppp0
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_get_options: get DHCP option server ID, len 10
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]:   DUID: 00:03:00:01:e4:d3:f1:e2:9a:00
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_get_options: get DHCP option client ID, len 10
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]:   DUID: 00:03:00:01:bc:ae:c5:c3:c3:8d
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_get_options: get DHCP option IA_PD, len 41
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]:   IA_PD: ID=0, T1=900, T2=1440
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: copyin_option: get DHCP option IA_PD prefix, len 25
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: copyin_option:   IA_PD prefix: 2003:xxxx:xxxx:bb00::/56 pltime=1800 vltime=14400
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_get_options: get DHCP option DNS, len 32
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: client6_script: script "/sbin/dhcp6c-state" terminated
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_remove_event: removing an event on ppp0, state=RENEW
    Dec 17 14:09:52 RT-N16 daemon.debug dhcp6c[741]: client6_recvreply: got an expected reply, sleeping.
    Dec 17 14:11:13 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br1) 2003:xxxx:xxxx:bb01::
    Dec 17 14:14:10 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br2) 2003:xxxx:xxxx:bb02::
    Dec 17 14:14:49 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br0) 2003:xxxx:xxxx:bb00::
    Dec 17 14:20:49 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br1) 2003:xxxx:xxxx:bb01::
    Dec 17 14:23:02 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br0) 2003:xxxx:xxxx:bb00::
    Dec 17 14:23:39 RT-N16 daemon.info dnsmasq-dhcp[871]: RTR-ADVERT(br2) 2003:xxxx:xxxx:bb02::
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: ia_timo: IA timeout for PD-0, state=ACTIVE
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_reset_timer: reset a timer on ppp0, state=RENEW, timeo=0, retrans=9842
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: client6_send: a new XID (b20b4) is generated
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: copy_option: set client ID (len 10)
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: copy_option: set server ID (len 10)
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: copy_option: set elapsed time (len 2)
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: copy_option: set option request (len 2)
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: copyout_option: set IA_PD prefix
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: copyout_option: set IA_PD
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: client6_send: send renew to ff02::1:2
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: client6_recv: receive reply from fe80::e6d3:f1ff:fee2:9a00 on ppp0
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_get_options: get DHCP option server ID, len 10
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]:   DUID: 00:03:00:01:e4:d3:f1:e2:9a:00
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_get_options: get DHCP option client ID, len 10
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]:   DUID: 00:03:00:01:bc:ae:c5:c3:c3:8d
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_get_options: get DHCP option IA_PD, len 41
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]:   IA_PD: ID=0, T1=900, T2=1440
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: copyin_option: get DHCP option IA_PD prefix, len 25
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: copyin_option:   IA_PD prefix: 2003:xxxx:xxxx:bb00::/56 pltime=1800 vltime=14400
    Dec 17 14:24:52 RT-N16 daemon.debug dhcp6c[741]: dhcp6_get_options: get DHCP option DNS, len 32
    @Sean B.: could you please show the changed function
    "dhcp6c_state_main" what it looks like right now and in additon also the diff/patch for the change?

    I think koitsu and/or toastman maybe have some sugguestions/improvements for the code or change itself.

    Thank you very much Sean B. :)

    I hope Toastman will apply this change (remove rapid commit && this one) to his branches.
     
    Last edited: Dec 17, 2016
    AndreDVJ likes this.
  40. Sean B.

    Sean B. LI Guru Member

    Changed the location of variable assignment per Koitsu's recommendation. Separated the removal of rapid-commit and changes to dhcp6c-state into 2 patches. Here they are if @Toastman or anyone else may be interested.

    Code:
     Patched against Toastman-ARM at commit: 432cd801061642dbe7900c4fe43b72cb7e0225cd
     Author: Sean Baughn <Sbaughn82@gmail.com>
     Date:   Sat Dec 17 14:03:42 2016 -0800
     
     Confirm dhcpv6 IP/prefix address has actually changed before restarting dnsmasq/httpd.
     Fix IPv6 IP not being updated in hosts file when a change occurs.
    
     There have been multiple reports from users experiencing excessive and frequent restarts
     of dnsmasq when IPv6 is enabled and no IP/prefix change has taken place. Dhcp6c frequently
     renewing a lease may result from serveral factors but a likely source is short timers set
     by ISPs on their dhcpv6 servers. This adds a check of the LAN interfaces current IPv6 IP
     against the IP stored in NVRAM. If they are different, dhcp6c-state is run in its entirety.
     If not, the process of updating NVRAM variables and restarting dnsmasq/httpd is bypassed.
     Updates to dns servers recevied by dhcp6c are performed in either case as dnsmasq actively
     polls for these changes and does not require a restart to implement them.
    
     Added a call to set_host_domain_name() when an IP change is confirmed so /etc/hosts
     is updated with the new IP.
    
    diff --git a/release/src-rt-6.x.4708/router/rc/dhcp.c b/release/src-rt-6.x.4708/router/rc/dhcp.c
    index 37934bd..9bcb94e 100644
    --- a/release/src-rt-6.x.4708/router/rc/dhcp.c
    +++ b/release/src-rt-6.x.4708/router/rc/dhcp.c
    @@ -436,6 +436,7 @@ void stop_dhcpc(void)
     int dhcp6c_state_main(int argc, char **argv)
     {
        char prefix[INET6_ADDRSTRLEN];
    +    char *lanif;
        struct in6_addr addr;
        int i, r;
    
    @@ -443,30 +444,31 @@ int dhcp6c_state_main(int argc, char **argv)
    
        if (!wait_action_idle(10)) return 1;
    
    -    nvram_set("ipv6_rtr_addr", getifaddr(nvram_safe_get("lan_ifname"), AF_INET6, 0));
    -
    -    // extract prefix from configured IPv6 address
    -    if (inet_pton(AF_INET6, nvram_safe_get("ipv6_rtr_addr"), &addr) > 0) {
    -        r = nvram_get_int("ipv6_prefix_length") ? : 64;
    -        for (r = 128 - r, i = 15; r > 0; r -= 8) {
    -            if (r >= 8)
    -                addr.s6_addr[i--] = 0;
    -            else
    -                addr.s6_addr[i--] &= (0xff << r);
    +    lanif = getifaddr(nvram_safe_get("lan_ifname"), AF_INET6, 0);
    +    if (!nvram_match("ipv6_rtr_addr", lanif)) {
    +        nvram_set("ipv6_rtr_addr", lanif);
    +        // extract prefix from configured IPv6 address
    +        if (inet_pton(AF_INET6, nvram_safe_get("ipv6_rtr_addr"), &addr) > 0) {
    +            r = nvram_get_int("ipv6_prefix_length") ? : 64;
    +            for (r = 128 - r, i = 15; r > 0; r -= 8) {
    +                if (r >= 8)
    +                    addr.s6_addr[i--] = 0;
    +                else
    +                    addr.s6_addr[i--] &= (0xff << r);
    +            }
    +            inet_ntop(AF_INET6, &addr, prefix, sizeof(prefix));
    +            nvram_set("ipv6_prefix", prefix);
            }
    -        inet_ntop(AF_INET6, &addr, prefix, sizeof(prefix));
    -        nvram_set("ipv6_prefix", prefix);
    +        // (re)start dnsmasq and httpd
    +        set_host_domain_name();
    +        start_dnsmasq();
    +        start_httpd();   
        }
    
        if (env2nv("new_domain_name_servers", "ipv6_get_dns")) {
            dns_to_resolv();
    -//        start_dnsmasq();    // (re)start KDB don't do twice!
        }
    
    -    // (re)start dnsmasq and httpd
    -    start_dnsmasq();
    -    start_httpd();
    -
        TRACE_PT("ipv6_get_dns=%s\n", nvram_safe_get("ipv6_get_dns"));
        TRACE_PT("end\n");
        return 0;
    Code:
     Patched against Toastman-ARM at commit: 432cd801061642dbe7900c4fe43b72cb7e0225cd
     Author: Sean Baughn <Sbaughn82@gmail.com>
     Date:   Sat Dec 17 14:15:12 2016 -0800
    
     Remove hard coded rapid-commit option.
    
     Rapid-comit reduces the messages required for dhcpv6 leases from 4 to 2. This requires
     both client AND server(s) to have this option enabled. If only the client is configured
     to use it the server(s) will return a standard advertisement instead of the expected reply
     message. Dhcp6c waits for timer to expire if no valid reply message is received and then
     will process an advertisement or send solicit. This may also be a cause of unnecessary release
     and solicits when an advertisement is received from a different server than originally issued
     the lease in a multi-server network and the servers are not rapid-commit enabled ( dhcp6c returns
     "unexpected_advertise" and generates new XID/reply ).
    
    diff --git a/release/src-rt-6.x.4708/router/rc/dhcp.c b/release/src-rt-6.x.4708/router/rc/dhcp.c
    index 37934bd..9bcb94e 100644
    --- a/release/src-rt-6.x.4708/router/rc/dhcp.c
    +++ b/release/src-rt-6.x.4708/router/rc/dhcp.c
    @@ -507,7 +509,6 @@ void start_dhcp6c(void)
             };
             fprintf(f,
                 " send ia-pd 0;\n"
    -            " send rapid-commit;\n"
                 " request domain-name-servers;\n"
                 " script \"/sbin/dhcp6c-state\";\n"
                 "};\n"
    
     
    Last edited: Dec 18, 2016
    AndreDVJ, Elfew and M_ars like this.
  41. koitsu

    koitsu Network Guru Member

    Sorry, I forgot something:

    Code:
    +    const char *lanif;
    
    This needs to become char *lanif (i.e. remove the const).
     
    M_ars likes this.
  42. Sean B.

    Sean B. LI Guru Member

    Done. Thanks!
     
  43. M_ars

    M_ars Network Guru Member

    perfect, good work Sean B. - both patches look very good
    And also thank you koitsu for your support

    @Toastman: Would it be possible to include both patches to your branches (ARM & MIPS) and make a new release? :)
     
    Last edited: Dec 18, 2016
  44. Toastman

    Toastman Super Moderator Staff Member Member

    I'm posting a provision RT-AC build 0508.8 for you to try out. It has Koitsu's UI updates (mostly cosmetic) and SeanB's two commits relating to dnsmasq restarts.
     
    Sean B. likes this.
  45. M_ars

    M_ars Network Guru Member

    Cool, thx - will try it out
    --> 510.8 will be a very nice update then :D
     
  46. svalx_

    svalx_ Connected Client Member

    I updated to 1.28.0510.8 MIPSR2Toastman-RT-N K26 USB VPN, but the rapid-commit option still present in dhcp6c.conf. And how I can check minor release version? On About page and SSH MOTD I see only Tomato Firmware v1.28.0510 MIPSR2Toastman-RT-N K26 USB VPN...
     
  47. Toastman

    Toastman Super Moderator Staff Member Member

    sorry about the typo

    ? I'll check the rapid commit...
     
  48. M_ars

    M_ars Network Guru Member

    I checked my tomato-Netgear-3500Lv2-K26USB-1.28.0510.8Toastman-RT-N-VPN.chk

    Everything looks ok :)

    Code:
    interface ppp0 {
     send ia-pd 0;
     request domain-name-servers;
     script "/sbin/dhcp6c-state";
    };
    id-assoc pd 0 {
     prefix ::/56 infinity;
     prefix-interface br0 {
      sla-id 0;
      sla-len 8;
            };
    };
    id-assoc na 0 { };
    @Toastman: i wanted to ask if you have some time to update git?
     
    Elfew and AndreDVJ like this.
  49. Toastman

    Toastman Super Moderator Staff Member Member

    Thx for that feedback.

    I'm extra busy at the moment, but updating git should be easy enough. Hopefully I can find time.
     

Share This Page