Unable to auto-update snapshots



  • Has something changed again?  I'm currently using the URL in the first post:

    http://snapshots.pfsense.org/FreeBSD_releng/10.1/i386/pfSense_HEAD/.updaters/

    But I'm receiving the error "Unable to check for updates."

    I'm currently running the following build, but this has been happening for the past week or so:

    2.2-BETA (i386) 
    built on Mon Nov 24 07:39:20 CST 2014 
    FreeBSD 10.1-RELEASE
    

    I'm not seeing anything in the logs about this.  I can still pull down and run the latest update manually.  Please let me know if you need any additional detail.

    Thanks!


  • Netgate Administrator

    Try using https.
    The version file appears to accessible by both http and https though. Could be unrelated, do you have general internet access from the box otherwise?

    Steve



  • @stephenw10:

    Try using https.
    The version file appears to accessible by both http and https though. Could be unrelated, do you have general internet access from the box otherwise?

    Steve

    Tried HTTPS but the same problem persists.  I do otherwise have connectivity out of the box.

    Thanks!


  • Netgate Administrator

    Can you do this?:

    [2.2-BETA][root@xtm5.localdomain]/root: fetch -o /dev/null http://snapshots.pfsense.org/FreeBSD_stable/10/i386/pfSense_HEAD/.updaters/version
    /dev/null                                     100% of   29  B  291 kBps 00m00s
    [2.2-BETA][root@xtm5.localdomain]/root: fetch -o /dev/null https://snapshots.pfsense.org/FreeBSD_stable/10/i386/pfSense_HEAD/.updaters/version
    /dev/null                                     100% of   29  B  291 kBps 00m00s
    
    

    Steve


  • Rebel Alliance Developer Netgate

    I split this thread off since it is not related to the other thread in which it was posted.



  • Sorry about that, jimp.

    stephenw10: Upon running the command you provided I received the following error:

    Certificate verification failed for /C=SE/O=AddTrust AB/OU=AddTrust External TTP Network/CN=AddTrust External CA Root
    675211580:error:14090086:SSL routines:SSL3_GET_SERVER_CERTIFICATE:certificate verify failed:/usr/pfSensesrc/src/secure/lib/libssl/../../../crypto/openssl/ssl/s3_clnt.c:1180:
    fetch: http://snapshots.pfsense.org/FreeBSD_stable/10/i386/pfSense_HEAD/.updaters/version: Authentication error
    

    But the following does work:

    fetch --no-verify-peer -o /dev/null http://snapshots.pfsense.org/FreeBSD_stable/10/i386/pfSense_HEAD/.updaters/version
    /dev/null                                     100% of   29  B  103 kBps 00m00s
    

  • Netgate Administrator

    Hmm, well that looks bad. Interestingly I can't access that url either any more. Try again:
    https://snapshots.pfsense.org/FreeBSD_releng/10.1/i386/pfSense_HEAD/.updaters/
    Could be there were some changes taking place. I don't know though.

    Steve



  • Same issue with: https://snapshots.pfsense.org/FreeBSD_releng/10.1/i386/pfSense_HEAD/.updaters/

    I was able to fix fetch by creating a symlink for the root cert bundle:

    sudo ln -sf /usr/local/share/certs/ca-root-nss.crt /etc/ssl/cert.pem
    
    fetch -o /dev/null https://snapshots.pfsense.org/FreeBSD_stable/10/i386/pfSense_HEAD/.updaters/version
    /dev/null                                     100% of   29  B  123 kBps 00m00s
    

    Unfortunately, this didn't fix auto-update :)


  • Netgate Administrator

    Hmm, bizzare.  :-\ It's still working here on my test box just fine, all four options. There is a redirect in place for 10 stable to 10.1 releng:

    [2.2-BETA][root@xtm5.localdomain]/root: fetch -o /dev/null http://snapshots.pfsense.org/FreeBSD_stable/10/i386/pfSense_HEAD/.updaters/version
    /dev/null                                     100% of   29  B  300 kBps 00m00s
    [2.2-BETA][root@xtm5.localdomain]/root: fetch -o /dev/null https://snapshots.pfsense.org/FreeBSD_stable/10/i386/pfSense_HEAD/.updaters/version
    /dev/null                                     100% of   29  B  298 kBps 00m00s
    [2.2-BETA][root@xtm5.localdomain]/root: fetch -o /dev/null https://snapshots.pfsense.org/FreeBSD_releng/10.1/i386/pfSense_HEAD/.updaters/version
    /dev/null                                     100% of   29  B  307 kBps 00m00s
    [2.2-BETA][root@xtm5.localdomain]/root: fetch -o /dev/null http://snapshots.pfsense.org/FreeBSD_releng/10.1/i386/pfSense_HEAD/.updaters/version
    /dev/null                                     100% of   29  B  209 kBps 00m00s
    
    

    There have been cert problems before but usually affecting everything. Do you have a bad system date that's rendering the cert invalid?
    I'd be tempted to re-install at thus point.

    Steve



  • I just manually installed the latest snapshot.  Perhaps a contributor turned on some additional debugging in the updater widget, but it spit out the following output:

    2.2-BETA (i386)
    built on Mon Nov 24 16:50:47 CST 2014
    FreeBSD 10.1-RELEASE
    …........ Warning: Cannot modify header information - headers already sent by (output started at /etc/inc/config.inc:45) in /usr/local/www/guiconfig.inc on line 48 Warning: Cannot modify header information - headers already sent by (output started at /etc/inc/config.inc:45) in /usr/local/www/guiconfig.inc on line 49 Warning: Cannot modify header information - headers already sent by (output started at /etc/inc/config.inc:45) in /usr/local/www/guiconfig.inc on line 50 Warning: Cannot modify header information - headers already sent by (output started at /etc/inc/config.inc:45) in /usr/local/www/guiconfig.inc on line 51 Warning: Cannot modify header information - headers already sent by (output started at /etc/inc/config.inc:45) in /usr/local/www/guiconfig.inc on line 52 Warning: Cannot modify header information - headers already sent by (output started at /etc/inc/config.inc:45) in /usr/local/www/guiconfig.inc on line 55 Warning: session_start(): Cannot send session cache limiter - headers already sent (output started at /etc/inc/config.inc:45) in /etc/inc/auth.inc on line 1362

    Unable to check for updates.



  • I think I finally figured it out… I'm using the new unbound DNS Resolver, and had the following option unchecked under System->General Setup:

    -Do not use the DNS Forwarder as a DNS server for the firewall

    I noticed I was getting a failed resolution for snapshots.pfsense.org, so I enabled that option and it started working correctly under the System->Firmware->Auto Update tab.  I'm still getting the extra debug output in the System information widget under "Version", but I think that's actually a PHP error in the latest build.

    I'll report back if it succeeds in finding the next update.  Thanks a lot for your help!



  • FYI - this did end up fixing the issue.



  • Same issue as emce, and unchecking that same box worked to fix it for me as well.


  • Rebel Alliance Developer Netgate

    Did you have any name servers filled in under System > General?



  • @jimp:

    Did you have any name servers filled in under System > General?

    I do.  I'm using Google's servers, followed by those of my ISP.

    On a related note, I'm continuing to see the erroneous output in the Version section of the System Information widget:

    2.2-BETA (i386)
    built on Tue Nov 25 11:51:07 CST 2014
    FreeBSD 10.1-RELEASE
    …........ Warning: Cannot modify header information - headers already sent by (output started at /etc/inc/config.inc:45) in /usr/local/www/guiconfig.inc on line 48 Warning: Cannot modify header information - headers already sent by (output started at /etc/inc/config.inc:45) in /usr/local/www/guiconfig.inc on line 49 Warning: Cannot modify header information - headers already sent by (output started at /etc/inc/config.inc:45) in /usr/local/www/guiconfig.inc on line 50 Warning: Cannot modify header information - headers already sent by (output started at /etc/inc/config.inc:45) in /usr/local/www/guiconfig.inc on line 51 Warning: Cannot modify header information - headers already sent by (output started at /etc/inc/config.inc:45) in /usr/local/www/guiconfig.inc on line 52 Warning: Cannot modify header information - headers already sent by (output started at /etc/inc/config.inc:45) in /usr/local/www/guiconfig.inc on line 55 Warning: session_start(): Cannot send session cache limiter - headers already sent (output started at /etc/inc/config.inc:45) in /etc/inc/auth.inc on line 1362


  • Rebel Alliance Developer Netgate

    Can you check /etc/resolv.conf to see if the name servers are actually there?



  • Sure thing.  Here's the contents:

    $ cat /etc/resolv.conf
    search <mydomain>.com
    nameserver 8.8.8.8
    nameserver 8.8.4.4
    nameserver 75.75.75.75
    nameserver 75.75.76.76</mydomain>
    

  • Rebel Alliance Developer Netgate

    In that case it should have been able to resolve, unless you can't reach any of those servers



  • I've tried toggling the "Do not use the DNS Forwarder as a DNS server for the firewall" option on and off, and can successfully reproduce the issue.  I don't seem to be having any other resolution issues off of this box at the moment.  Definitely odd.



  • anything relevant in your resolver log? Status>System logs, Resolver.

    What does the output of:

    sockstat -4 | grep 53
    

    run from a command prompt show?



  • Ok… scratch me from having the problem. I was actually having an issue with unbound (see that thread). I just unchecked that setting and it's still checking for updates.



  • I'm assuming you'd like this output from the "error" state, ie, "Do not use the DNS Forwarder as a DNS server for the firewall" is toggled off for the following…

    Current sockstat output:

    $ sockstat -4 | grep 53
    unbound  unbound    67721 10 udp4   10.0.0.1:53           *:*
    unbound  unbound    67721 11 tcp4   10.0.0.1:53           *:*
    unbound  unbound    67721 12 tcp4   127.0.0.1:953         *:*
    root     miniupnpd  40431 16 udp4   10.0.0.1:5351         *:*
    ?        ?          ?     ?  tcp4   <myip>:53366   192.12.94.30:53
    ?        ?          ?     ?  tcp4   <myip>:12766   192.41.162.30:53</myip></myip>
    

    I didn't notice anything relevant in the resolver log, but this basic block is repeated:

    Nov 25 18:18:32	unbound: [1038:0] info: start of service (unbound 1.4.22).
    Nov 25 18:18:32	unbound: [1038:0] notice: init module 1: iterator
    Nov 25 18:18:32	unbound: [1038:0] notice: init module 0: validator
    Nov 25 18:18:32	unbound: [1038:0] notice: Restart of unbound 1.4.22.
    Nov 25 18:18:32	unbound: [1038:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0
    Nov 25 18:18:32	unbound: [1038:0] info: server stats for thread 1: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch
    Nov 25 18:18:32	unbound: [1038:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
    Nov 25 18:18:32	unbound: [1038:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch
    Nov 25 18:18:32	unbound: [1038:0] info: service stopped (unbound 1.4.22).
    Nov 25 18:18:31	unbound: [1038:0] info: start of service (unbound 1.4.22).
    Nov 25 18:18:31	unbound: [1038:0] notice: init module 1: iterator
    Nov 25 18:18:31	unbound: [1038:0] notice: init module 0: validator
    Nov 25 18:18:31	unbound: [1038:0] notice: Restart of unbound 1.4.22.
    Nov 25 18:18:31	unbound: [1038:0] info: server stats for thread 1: requestlist max 0 avg 0 exceeded 0 jostled 0
    Nov 25 18:18:31	unbound: [1038:0] info: server stats for thread 1: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch
    Nov 25 18:18:31	unbound: [1038:0] info: server stats for thread 0: requestlist max 0 avg 0 exceeded 0 jostled 0
    Nov 25 18:18:31	unbound: [1038:0] info: server stats for thread 0: 0 queries, 0 answers from cache, 0 recursions, 0 prefetch
    Nov 25 18:18:31	unbound: [1038:0] info: service stopped (unbound 1.4.22).
    Nov 25 18:18:31	unbound: [1038:0] info: start of service (unbound 1.4.22).
    Nov 25 18:18:31	unbound: [1038:0] notice: init module 1: iterator
    Nov 25 18:18:31	unbound: [1038:0] notice: init module 0: validator
    Nov 25 18:18:30	unbound: [67721:0] info: 1.000000 2.000000 6
    Nov 25 18:18:30	unbound: [67721:0] info: 0.524288 1.000000 14
    Nov 25 18:18:30	unbound: [67721:0] info: 0.262144 0.524288 6
    Nov 25 18:18:30	unbound: [67721:0] info: 0.131072 0.262144 2
    Nov 25 18:18:30	unbound: [67721:0] info: 0.065536 0.131072 13
    Nov 25 18:18:30	unbound: [67721:0] info: 0.032768 0.065536 15
    Nov 25 18:18:30	unbound: [67721:0] info: 0.016384 0.032768 10
    Nov 25 18:18:30	unbound: [67721:0] info: 0.008192 0.016384 2
    Nov 25 18:18:30	unbound: [67721:0] info: 0.000000 0.000001 5
    Nov 25 18:18:30	unbound: [67721:0] info: lower(secs) upper(secs) recursions
    Nov 25 18:18:30	unbound: [67721:0] info: [25%]=0.0354987 median[50%]=0.0882215 [75%]=0.583752
    Nov 25 18:18:30	unbound: [67721:0] info: histogram of recursion processing times
    Nov 25 18:18:30	unbound: [67721:0] info: average recursion processing time 0.301498 sec
    Nov 25 18:18:30	unbound: [67721:0] info: server stats for thread 1: requestlist max 19 avg 3.60811 exceeded 0 jostled 0
    Nov 25 18:18:30	unbound: [67721:0] info: server stats for thread 1: 87 queries, 14 answers from cache, 73 recursions, 1 prefetch
    


  • You're not binding to localhost, so it fails when you tell it to use localhost.

    That should skip 127.0.0.1 being added to resolv.conf in that circumstance to avoid breaking with such misconfigurations. There's a problem of some sort there, looking.



  • I didn't notice anything relevant in the resolver log, but this basic block is repeated:

    Just a note to say that this seems to be normal behavior on startup. I guess it starts and then sends it SIGHUP or whatever messages that are causing it to reload (what would be an unchanged config at that point). I don't think any harm is done. A side-issue to the issue of this thread.
    Ref this post: https://forum.pfsense.org/index.php?topic=84474.0



  • @cmb:

    You're not binding to localhost, so it fails when you tell it to use localhost

    I've updated the resolver to bind to localhost as well as the LAN IP and it did correct the issue.  I don't remember modifying that, but apparently I did at some point.

    Thanks!



  • @cmb:

    You're not binding to localhost, so it fails when you tell it to use localhost.

    That should skip 127.0.0.1 being added to resolv.conf in that circumstance to avoid breaking with such misconfigurations.

    That problem is fixed.

    While there, I also added input validation so if you have the system configured in such a way that 127.0.0.1 would normally end up in resolv.conf, it forces you to pick Localhost in the bindings list in Unbound or check "Do not use the DNS Forwarder as a DNS server for the firewall" to allow it to be omitted.