Netgate Discussion Forum
    • Categories
    • Recent
    • Tags
    • Popular
    • Users
    • Search
    • Register
    • Login

    Unbound did not start upon first boot after update to RC

    Scheduled Pinned Locked Moved
    2.3-RC Snapshot Feedback and Issues - ARCHIVED
    3
    3
    1.4k
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • H
      heper
      last edited by

      can't remember having this issue, with it  any of the previous snapshots .

      unbound started fine after second boot

      follow timestamps & not top->bottom
      out from status_logs.php?logfile=resolver:

      
Apr 1 14:27:41 	filterdns 		adding entry 191.232.139.254 to table winspy on host vortex-win.data.microsoft.com
Apr 1 14:27:41 	filterdns 		adding entry 191.232.139.253 to table winspy on host settings-win.data.microsoft.com
Apr 1 14:27:33 	unbound 	70364:0 	info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
Apr 1 14:27:33 	unbound 	70364:0 	info: server stats for thread 0: 1 queries, 0 answers from cache, 1 recursions, 0 prefetch
Apr 1 14:27:33 	unbound 	70364:0 	info: service stopped (unbound 1.5.5).
Apr 1 14:27:33 	unbound 	70364:0 	info: start of service (unbound 1.5.5).
Apr 1 14:27:33 	unbound 	70364:0 	notice: init module 1: iterator
Apr 1 14:27:33 	unbound 	70364:0 	notice: init module 0: validator
Apr 1 14:27:33 	unbound 	70364:0 	notice: Restart of unbound 1.5.5.
Apr 1 14:27:33 	unbound 	70364:0 	info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
Apr 1 14:27:33 	unbound 	70364:0 	info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch
Apr 1 14:27:33 	unbound 	70364:0 	info: service stopped (unbound 1.5.5).
Apr 1 14:27:32 	unbound 	70364:0 	info: start of service (unbound 1.5.5).
Apr 1 14:27:32 	unbound 	70364:0 	notice: init module 1: iterator
Apr 1 14:27:32 	unbound 	70364:0 	notice: init module 0: validator
Apr 1 14:27:32 	unbound 	31770:0 	info: 0.524288 1.000000 2
Apr 1 14:27:32 	unbound 	31770:0 	info: 0.262144 0.524288 4
Apr 1 14:27:32 	unbound 	31770:0 	info: 0.131072 0.262144 6
Apr 1 14:27:32 	unbound 	31770:0 	info: 0.065536 0.131072 2
Apr 1 14:27:32 	unbound 	31770:0 	info: 0.032768 0.065536 1
Apr 1 14:27:32 	unbound 	31770:0 	info: 0.016384 0.032768 1
Apr 1 14:27:32 	unbound 	31770:0 	info: lower(secs) upper(secs) recursions
Apr 1 14:27:32 	unbound 	31770:0 	info: [25%]=0.131072 median[50%]=0.218453 [75%]=0.393216
Apr 1 14:27:32 	unbound 	31770:0 	info: histogram of recursion processing times
Apr 1 14:27:32 	unbound 	31770:0 	info: average recursion processing time 0.256180 sec
Apr 1 14:27:32 	unbound 	31770:0 	info: server stats for thread 0: requestlist max 35 avg 17.5625 exceeded 0 jostled 0
Apr 1 14:27:32 	unbound 	31770:0 	info: server stats for thread 0: 20 queries, 4 answers from cache, 16 recursions, 0 prefetch
Apr 1 14:27:32 	unbound 	31770:0 	info: service stopped (unbound 1.5.5).
Apr 1 14:27:29 	unbound 	31770:0 	info: start of service (unbound 1.5.5).
Apr 1 14:27:29 	unbound 	31770:0 	notice: init module 1: iterator
Apr 1 14:27:29 	unbound 	31770:0 	notice: init module 0: validator
Apr 1 14:27:29 	unbound 	31770:0 	notice: Restart of unbound 1.5.5.
Apr 1 14:27:29 	unbound 	31770:0 	info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
Apr 1 14:27:29 	unbound 	31770:0 	info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch
Apr 1 14:27:29 	unbound 	31770:0 	info: service stopped (unbound 1.5.5).
Apr 1 14:27:29 	unbound 	31770:0 	info: start of service (unbound 1.5.5).
Apr 1 14:27:29 	unbound 	31770:0 	notice: init module 1: iterator
Apr 1 14:27:29 	unbound 	31770:0 	notice: init module 0: validator
Apr 1 14:27:23 	kernel 		filterdns: 1.0_8 -> 1.0_9 [pfSense]

      MANUAL start of unbound service from GUI:

      
Apr 1 14:31:12 	unbound 	77650:0 	info: start of service (unbound 1.5.5).
Apr 1 14:31:12 	unbound 	77650:0 	notice: init module 1: iterator
Apr 1 14:31:12 	unbound 	77650:0 	notice: init module 0: validator
Apr 1 14:31:12 	unbound 	77650:0 	notice: Restart of unbound 1.5.5.
Apr 1 14:31:12 	unbound 	77650:0 	info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
Apr 1 14:31:12 	unbound 	77650:0 	info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch
Apr 1 14:31:12 	unbound 	77650:0 	info: service stopped (unbound 1.5.5).
Apr 1 14:31:12 	unbound 	77650:0 	info: start of service (unbound 1.5.5).
Apr 1 14:31:12 	unbound 	77650:0 	notice: init module 1: iterator
Apr 1 14:31:12 	unbound 	77650:0 	notice: init module 0: validator
Apr 1 14:31:12 	unbound 	77650:0 	notice: Restart of unbound 1.5.5.
Apr 1 14:31:12 	unbound 	77650:0 	info: server stats for thread 0: requestlist max 4 avg 2.25 exceeded 0 jostled 0
Apr 1 14:31:12 	unbound 	77650:0 	info: server stats for thread 0: 4 queries, 0 answers from cache, 4 recursions, 0 prefetch
Apr 1 14:31:12 	unbound 	77650:0 	info: service stopped (unbound 1.5.5).
Apr 1 14:31:12 	unbound 	77650:0 	info: start of service (unbound 1.5.5).
Apr 1 14:31:11 	unbound 	77650:0 	notice: init module 1: iterator
Apr 1 14:31:11 	unbound 	77650:0 	notice: init module 0: validator
Apr 1 14:31:11 	unbound 	77650:0 	notice: Restart of unbound 1.5.5.
Apr 1 14:31:11 	unbound 	77650:0 	info: 0.262144 0.524288 2
Apr 1 14:31:11 	unbound 	77650:0 	info: 0.131072 0.262144 2
Apr 1 14:31:11 	unbound 	77650:0 	info: 0.032768 0.065536 1
Apr 1 14:31:11 	unbound 	77650:0 	info: lower(secs) upper(secs) recursions
Apr 1 14:31:11 	unbound 	77650:0 	info: [25%]=0.147456 median[50%]=0.229376 [75%]=0.360448
Apr 1 14:31:11 	unbound 	77650:0 	info: histogram of recursion processing times
Apr 1 14:31:11 	unbound 	77650:0 	info: average recursion processing time 0.204544 sec
Apr 1 14:31:11 	unbound 	77650:0 	info: server stats for thread 0: requestlist max 16 avg 7.2 exceeded 0 jostled 0
Apr 1 14:31:11 	unbound 	77650:0 	info: server stats for thread 0: 15 queries, 10 answers from cache, 5 recursions, 0 prefetch
Apr 1 14:31:11 	unbound 	77650:0 	info: service stopped (unbound 1.5.5).
Apr 1 14:31:10 	unbound 	77650:0 	info: start of service (unbound 1.5.5).
Apr 1 14:31:10 	unbound 	77650:0 	notice: init module 1: iterator
Apr 1 14:31:10 	unbound 	77650:0 	notice: init module 0: validator
Apr 1 14:31:10 	unbound 	77650:0 	notice: Restart of unbound 1.5.5.
Apr 1 14:31:10 	unbound 	77650:0 	info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
Apr 1 14:31:10 	unbound 	77650:0 	info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch
Apr 1 14:31:10 	unbound 	77650:0 	info: service stopped (unbound 1.5.5).
Apr 1 14:31:10 	unbound 	77650:0 	info: start of service (unbound 1.5.5).
Apr 1 14:31:10 	unbound 	77650:0 	notice: init module 1: iterator
Apr 1 14:31:10 	unbound 	77650:0 	notice: init module 0: validator
      1 Reply Last reply Reply Quote 0
      • Z
        Zaphon
        last edited by

        I had this happen in one of the prior builds (unbound that is).  And now I have a situation where instead of something not starting (IPSEC in my case), it's starting twice and causing just as much havoc as not starting.

        1 Reply Last reply Reply Quote 0
        • ?
          A Former User
          last edited by

          "can't remember having this issue, with it  any of the previous snapshots"
          I started using the Beta March 20th and after any update requiring a reboot also needed a restart of unbound to get the log file showing it was indeed running. After reboot I also had to "Reload" the DNSBL to get it showing in the widget for that database.
          Also I found the running/stopped icon not showing unbound as stopped. It always showed as running.
          Still, thank you for a great firewall. Everything else went very smoothly in the upgrade to RC.

          1 Reply Last reply Reply Quote 0
          • First post
            Last post