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 LI 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::
     

Share This Page