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

Odd log entries every 30 minutes

Discussion in 'Tomato Firmware' started by LanceMoreland, Jun 28, 2013.

  1. LanceMoreland

    LanceMoreland Network Guru Member

    Edit: I see others are having the same issue here: http://tomatousb.org/forum/t-431452/e4200-importune-reboot-issue

    This just started the other day. Can someone tell me what they mean. I am getting them every half hour:

    Jun 28 00:09:05 Tomato-1 user.debug init[1]: 182: pptp peerdns disabled
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq[3352]: reading /etc/resolv.dnsmasq
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq[3352]: using nameserver 75.75.76.76#53
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq[3352]: using nameserver 75.75.75.75#53
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq[3352]: using nameserver 2001:558:feed::1#53
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq[3352]: using nameserver 2001:558:feed::2#53
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq[3352]: exiting on receipt of SIGTERM
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq[3374]: started, version 2.67cs7 cachesize 1500
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq[3374]: 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
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq[3374]: asynchronous logging enabled, queue limit is 5 messages
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq-dhcp[3374]: DHCP, IP range 192.168.1.100 -- 192.168.1.149, lease time 1d
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq-dhcp[3374]: DHCPv4-derived IPv6 names on 2601:1:8000:90::
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq-dhcp[3374]: router advertisement on 2601:1:8000:90::
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq-dhcp[3374]: IPv6 router advertisement enabled
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq[3374]: reading /etc/resolv.dnsmasq
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq[3374]: using nameserver 75.75.76.76#53
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq[3374]: using nameserver 75.75.75.75#53
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq[3374]: using nameserver 2001:558:feed::1#53
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq[3374]: using nameserver 2001:558:feed::2#53
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq[3374]: read /etc/hosts - 3 addresses
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq[3374]: read /etc/dnsmasq/hosts/hosts - 31 addresses
    Jun 28 00:09:05 Tomato-1 daemon.info dnsmasq-dhcp[3374]: read /etc/dnsmasq/dhcp/dhcp-hosts
    Jun 28 00:39:05 Tomato-1 user.debug init[1]: 182: pptp peerdns disabled
    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq[3374]: exiting on receipt of SIGTERM
    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq[3382]: started, version 2.67cs7 cachesize 1500
    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq[3382]: 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
    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq[3382]: asynchronous logging enabled, queue limit is 5 messages
    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq-dhcp[3382]: DHCP, IP range 192.168.1.100 -- 192.168.1.149, lease time 1d
    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq-dhcp[3382]: DHCPv4-derived IPv6 names on 2601:1:8000:90::
    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq-dhcp[3382]: router advertisement on 2601:1:8000:90::
    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq-dhcp[3382]: IPv6 router advertisement enabled
    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq[3382]: reading /etc/resolv.dnsmasq
    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq[3382]: using nameserver 75.75.76.76#53
    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq[3382]: using nameserver 75.75.75.75#53
    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq[3382]: using nameserver 2001:558:feed::1#53
    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq[3382]: using nameserver 2001:558:feed::2#53
    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq[3382]: read /etc/hosts - 3 addresses
    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq[3382]: read /etc/dnsmasq/hosts/hosts - 31 addresses
    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq-dhcp[3382]: read /etc/dnsmasq/dhcp/dhcp-hosts
     
  2. Monk E. Boy

    Monk E. Boy Network Guru Member

    Jun 28 00:39:05 Tomato-1 daemon.info dnsmasq[3374]: exiting on receipt of SIGTERM

    Means that the dnsmasq is being quit/ended/exited. dnsmasq is stopping, in other words.

    The messages that follow (up to the next "exiting on receipt") are normal startup messages for dnsmasq.

    So, basically, every 30 minutes dnsmasq, which handles DHCP & DNS duties in Tomato, is being quit and reloaded.

    As to why? We'll need to know what Tomato build you're running, the version, and probably some more technical details about your setup... internet connection type, IPv6 enabled/disabled, etc.
     
  3. LanceMoreland

    LanceMoreland Network Guru Member

    I am running Toastman's Latest version:
    tomato-E4200USB-NVRAM60K-1.28.0502.8MIPSR2Toastman-RT-N-VPN (beta)

    On an E4200 v1. IPv6 is enabled. I am on Comcast and I have IPv6 set up as follows:
    DHCPv6 with prefix delegation. RA from WAN.

    Edit: I just flashed back (dirty flashed so the nvram variables are the same) to tomato-E4200USB-NVRAM60K-1.28.0502.1MIPSR2Toastman-RT-N-VPN and now I am getting these entries every 30 minutes:

    Jun 28 16:18:26 Tomato-1 daemon.warn radvd[1538]: Exiting, sigterm or sigint received.
    Jun 28 16:18:26 Tomato-1 daemon.info radvd[1545]: version 1.8.1 started
    Jun 28 16:48:26 Tomato-1 daemon.warn radvd[1547]: Exiting, sigterm or sigint received.
    Jun 28 16:48:26 Tomato-1 daemon.info radvd[1600]: version 1.8.1 started

    This version of tomato uses radvd for IVp6, so what could be the cause of these restarts?


    Edit #2: Clearing nvram and reconfiguring makes no difference.
     
  4. Monk E. Boy

    Monk E. Boy Network Guru Member

    Sorry, got crazy busy at work... what happens under 0502.1?

    .8 is a beta build and a work in progress, so unless you're inclined to debug quirky stuff like this it would be wise to avoid it until they get all the issues sorted out.
     
  5. LanceMoreland

    LanceMoreland Network Guru Member

    Samething except now it just restarts radvd every thirty minutes.
     
  6. koitsu

    koitsu Network Guru Member

    I believe I remember reading somewhere about how some TomatoUSB piece of code periodically calls a function that reloads a bunch of services, and that it has come under scrutiny in the past for reloading/restarting services that are irrelevant based on what's needed at the time. I can't remember what thread that was in though.

    Debugging this is sadly difficult, as it requires one to really reverse-engineer the code and work backwards.
     
  7. Monk E. Boy

    Monk E. Boy Network Guru Member

    Any chance your IPv6 DHCP lease is only 30 or 60 minutes long? At the 50% mark (half the lease time) a client device will attempt to negotiate a longer lease for the IP address. Under 0502.1 radvd is just used for IPv6 so it's got to be something related to your IPv6 tunnel/lease.
     
  8. Morac

    Morac Network Guru Member

    Comcast changed my IP address and boosted my speeds from 50 Mbps to 100 Mbps this past week and did something with their DNS servers this week that caused them to go offline for several hours. Now I'm seeing the same thing as what's posted in this thread. Every 30 minutes dnsmasq is terminated and restarted. I thought it was related to pptp so I turned that off and rebooted the router (E3000), but it made no difference.

    I'm seeing the the original poster has the same DNS servers for ipv4 and ipv6 so he must be Comcast too.
    Did you ever solve this?

    I know it's an old version, but I've been running Toastman v1.28.7502 MIPSR2Toastman-RT K26 USB VPN for months without issue. Something Comcast did must be causing this problem. My IP lease is 3 days, at least that's what's listed.


    What is the "pptp peerdns disabled" line that appears right before the SIGTERM?


    Code:
    Apr 13 03:40:38 unknown cron.err crond[575]: time disparity of 23289579 minutes detected
    Apr 13 04:00:01 unknown syslog.info root: -- MARK --
    Apr 13 04:09:49 unknown user.debug init[1]: 182: pptp peerdns disabled
    Apr 13 04:09:49 unknown daemon.info dnsmasq[1020]: exiting on receipt of SIGTERM
    Apr 13 04:09:49 unknown daemon.info dnsmasq[1197]: started, version 2.67cs7 cachesize 1500
    Apr 13 04:09:49 unknown daemon.info dnsmasq[1197]: 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
    Apr 13 04:09:49 unknown daemon.info dnsmasq[1197]: asynchronous logging enabled, queue limit is 5 messages
    Apr 13 04:09:49 unknown daemon.info dnsmasq-dhcp[1197]: DHCP, IP range 192.168.1.100 -- 192.168.1.149, lease time 7d
    Apr 13 04:09:49 unknown daemon.info dnsmasq-dhcp[1197]: DHCPv4-derived IPv6 names on x:x:x:2eb::
    Apr 13 04:09:49 unknown daemon.info dnsmasq-dhcp[1197]: router advertisement on x:x:x:2eb::
    Apr 13 04:09:49 unknown daemon.info dnsmasq-dhcp[1197]: IPv6 router advertisement enabled
    Apr 13 04:09:49 unknown daemon.info dnsmasq[1197]: reading /etc/resolv.dnsmasq
    Apr 13 04:09:49 unknown daemon.info dnsmasq[1197]: using nameserver 75.75.76.76#53
    Apr 13 04:09:49 unknown daemon.info dnsmasq[1197]: using nameserver 75.75.75.75#53
    Apr 13 04:09:49 unknown daemon.info dnsmasq[1197]: using nameserver 2001:558:feed::2#53
    Apr 13 04:09:49 unknown daemon.info dnsmasq[1197]: using nameserver 2001:558:feed::1#53
    Apr 13 04:09:49 unknown daemon.info dnsmasq[1197]: read /etc/hosts - 3 addresses
    Apr 13 04:09:49 unknown daemon.info dnsmasq[1197]: read /etc/dnsmasq/hosts/hosts - 8 addresses
    Apr 13 04:09:49 unknown daemon.info dnsmasq-dhcp[1197]: read /etc/dnsmasq/dhcp/dhcp-hosts
    
     
    Last edited: Apr 13, 2014

Share This Page