User unbound does not exist but it does



  • Mar 6 09:50:58 	unbound: [36355:0] error: user 'unbound' does not exist.
    Mar 6 09:50:58 	unbound: [36355:0] notice: Restart of unbound 1.5.2.
    Mar 6 09:50:58 	unbound: [36355:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0
    Mar 6 09:50:58 	unbound: [36355:0] info: server stats for thread 1: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch
    Mar 6 09:50:58 	unbound: [36355:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
    Mar 6 09:50:58 	unbound: [36355:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch
    Mar 6 09:50:58 	unbound: [36355:0] info: service stopped (unbound 1.5.2).
    Mar 6 09:50:58 	unbound: [36355:0] info: start of service (unbound 1.5.2).
    Mar 6 09:50:58 	unbound: [36355:0] notice: init module 0: iterator
    

    I got this when I upgraded a test APU from 2.2-RELEASE to:
    2.2.1-DEVELOPMENT (amd64)
    built on Thu Mar 05 18:16:04 CST 2015
    FreeBSD 10.1-RELEASE-p6

    nanoBsd 4GB 64-bit image

    When I press the start button for unbound from the GUI, this comes in the resolver log:

    Mar 6 11:14:55 	unbound: [20584:0] error: user 'unbound' does not exist.
    Mar 6 11:14:55 	unbound: [20584:0] notice: Restart of unbound 1.5.2.
    Mar 6 11:14:55 	unbound: [20584:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0
    Mar 6 11:14:55 	unbound: [20584:0] info: server stats for thread 1: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch
    Mar 6 11:14:55 	unbound: [20584:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
    Mar 6 11:14:55 	unbound: [20584:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch
    Mar 6 11:14:55 	unbound: [20584:0] info: service stopped (unbound 1.5.2).
    Mar 6 11:14:55 	unbound: [20584:0] info: start of service (unbound 1.5.2).
    Mar 6 11:14:55 	unbound: [20584:0] notice: init module 0: iterator
    

    But /etc/passwd has:

    ...
    mailnull:*:26:26:Sendmail Default User:/var/spool/mqueue:/usr/sbin/nologin
    bind:*:53:53:Bind Sandbox:/:/usr/sbin/nologin
    unbound:*:59:59:Unbound DNS Resolver:/var/unbound:/usr/sbin/nologin
    proxy:*:62:62:Packet Filter pseudo-user:/nonexistent:/usr/sbin/nologin
    _pflogd:*:64:64:pflogd privsep user:/var/empty:/usr/sbin/nologin
    ...
    

    So why "user unbound does not exist"?


  • Rebel Alliance Developer Netgate

    Try rebuilding the passwd database

    /usr/sbin/pwd_mkdb -d /etc -p /etc/master.passwd
    


  • [2.2.1-DEVELOPMENT][root@apu22.localdomain]/root: /etc/rc.conf_mount_rw
    [2.2.1-DEVELOPMENT][root@apu22.localdomain]/root: /usr/sbin/pwd_mkdb -d /etc -p /etc/master.passwd
    
    

    Still unbound starts and dies like:

    Mar 6 22:07:17 	unbound: [98897:0] error: user 'unbound' does not exist.
    Mar 6 22:07:17 	unbound: [98897:0] notice: Restart of unbound 1.5.2.
    Mar 6 22:07:17 	unbound: [98897:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0
    Mar 6 22:07:17 	unbound: [98897:0] info: server stats for thread 1: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch
    Mar 6 22:07:17 	unbound: [98897:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
    Mar 6 22:07:17 	unbound: [98897:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch
    Mar 6 22:07:17 	unbound: [98897:0] info: service stopped (unbound 1.5.2).
    Mar 6 22:07:17 	unbound: [98897:0] info: start of service (unbound 1.5.2).
    Mar 6 22:07:17 	unbound: [98897:0] notice: init module 0: iterator
    

    Note: my posts of logs are backwards - logs from the bottom up in time sequence.

    I tried with mounted rw and ro and that makes no difference.

    Anyway, I am happy to try a later snapshot tomorrow. I suspect an error message like this should happen all the time for anyone using this snapshot.


  • Banned

    Never seen that anywhere. What I'm seeing on loads of nanobsd/Alix boxes is this:

    
    Jan 1 01:01:20	unbound: [30248:0] info: failed to prime trust anchor -- DNSKEY rrset is not secure . DNSKEY IN
    Jan 1 01:01:20	unbound: [30248:0] info: failed to prime trust anchor -- DNSKEY rrset is not secure . DNSKEY IN
    Jan 1 01:01:20	unbound: [30248:0] info: failed to prime trust anchor -- DNSKEY rrset is not secure . DNSKEY IN
    
    

    Note the wrong date. (Yeah, those boxes do have a CMOS battery.)



  • @phil.davis:

    Still unbound starts and dies like:

    I'm seeing exactly the same thing on only one system. The user is there, the password database is up to date (and tried rebuilding it), yet it dies with the log it can't find the user. Running same snapshot (latest available at the time of this writing) on several systems, and the rest have no issue. Have dozens of systems on recent snapshots, not seeing an issue on any of those either. No apparent difference between the ones that work, and the one that doesn't. Looking into it.



  • Unbound 1.5.2 regression, 1.5.3 was just released to address it.
    https://redmine.pfsense.org/issues/4514

    Renato will get that in snapshots in the next few hours. We're very near to releasing 2.2.1, so help testing once that's updated would be appreciated.



  • Good to know I am not going crazy. Post when there is a snap available, I can test quite quickly.



  • I looked on a Firebox X1000 running yesterday's 2.2.1 snapshot and unbound was not crashing or getting this error by itself.
    I can make it do a bad thing by:

    [2.2.1-DEVELOPMENT][root@test-rt-01.myorg.org]/root: unbound-control -c /var/unbound/unbound.conf reload
    ok
    
    

    Then in the system log:

    Mar 12 15:04:12 	kernel: pid 33159 (unbound), uid 59: exited on signal 11
    

    and in this case the unbound log has nothing - it seems the reload crashes unbound before it can write the log message about "user unbound does not exist."
    Ref: https://www.nlnetlabs.nl/bugs-script/show_bug.cgi?id=650

    This seems like an easy test that should exhibit the problem on (all?) systems. Then it can be done on a snapshot with unbound 1.5.3 to confirm it is fixed.



  • that fixed unbound for me



  • @cmb:

    Unbound 1.5.2 regression, 1.5.3 was just released to address it.
    https://redmine.pfsense.org/issues/4514

    Renato will get that in snapshots in the next few hours. We're very near to releasing 2.2.1, so help testing once that's updated would be appreciated.

    Hi,

    I had the problem this morning with a fresh install on an APU board.

    After upgrading to
    2.2.1-DEVELOPMENT (amd64)
    built on Thu Mar 12 08:52:42 CDT 2015
    FreeBSD 10.1-RELEASE-p6

    the problem was solved.

    Thanks for the quick fix,
    bootix



  • Fixed for me also with same snapshot.


Log in to reply