Captive Portal fails regularly after upgrading from 2.0.1 to 2.0.2



  • I have come across a problem with the captive portal since I upgraded from 2.0.1 to 2.0.2.

    I notice sometimes that whilst viewing the service status on the dashboard, the captive portal is reported it as being stopped, if I check diag_logs I find the following

    Dec 27 19:36:15 minicron: (/etc/rc.prunecaptiveportal) terminated by signal 15 (Terminated: 15)

    However if I try to restart the service I come across the following error on both diag_logs and diag_logs_auth

    Dec 27 19:36:51 php[8017]: /services_captiveportal.php: The command '/usr/local/sbin/lighttpd -f /var/etc/lighty-CaptivePortal.conf' returned exit code '255', the output was '2012-12-27 19:36:51: (network.c.385) can't bind to port: 8000 Address already in use'

    As this is a production system and needs to be fully functional all the time, the only way to get it working again is a reboot, I have searched the forum for a solution and found similar problems but those relate to 2.1 and captive portal zones.

    My environment consists of ESXI 5.0 hosts, switches (and vlans but none are configured through pfsense) AP's and loads of vm's, one of them being my pfsense firewall.

    As this is an upgrade from 2.0.1 and I dont have any other problems apart from that…even a remote location upgraded flawlessly.  I may try doing a fresh install and importing my config and see if that solves anything.

    Any suggestions?

    EDIT: I forgot to mention I am running User/Voucher auth with captive portal.



  • I emailed you to see if we can arrange getting access to the system to troubleshoot.



  • Thanks Chris, Ive just emailed you back.



  • There is some kind of other problem there, but the big issue is you have your DHCP lease length too short for the CP hard timeout you have configured. With your 6 hour hard timeout, your DHCP lease length must be at least 6 hours and it's only 1 hour. If the IP is reassigned to a different device before the CP session expires, it won't work by design (IP-MAC association is enforced for the duration of the session).

    I didn't change anything on your system, but you'll definitely need to up your DHCP lease length to at least 6 hours.



  • The 'default lease time' I have always had on most of my interfaces is '86400' which is 24hrs, I have always left the 'maximum lease time' blank as the notes state "This is the maximum lease time for clients that ask for a specific expiration time.
    The default is 86400 seconds.", because of that I assumed my config would have a min & max lease time of '86400' or 24hrs.

    Could this be the problem? that I need to set a maximum lease time as well, say a week?

    Im curious to know where you saw the lease time set to 1 hour, the only thing I have set to 1 hour is the 'idle timeout' under cp page.



  • Hello, i have the SAME problem after upgrading:

    php: /status_services.php: The command '/usr/local/sbin/lighttpd -f /var/etc/lighty-CaptivePortal.conf' returned exit code '255', the output was '2012-12-29 23:01:23: (network.c.385) can't bind to port: 8000 Address already in use'

    The captive portal is reported as being stopped, also after rebbooting.

    The DHCP-Lease-Time is 43200 sec, the Captive-Portal Timeout times are 720 min

    Somebody any idea?

    Is it possible to change to Ver. 2.1 und to import the backup (config-file.xml) of Ver. 2.0.2?



  • This error happened to me again late evening, I noticed the dashboard status showing captive portal as stopped, I was on a call at the time so when I came back and refreshed the dashboard I found the captive portal service status was shown as working, nothing in the logs, not even the original error, strange.



  • Exactly the same problems and messages here. I had to revert to 2.0.1 to get things working reliable again.

    Standalone machine, no VM, plain upgrade from 2.0.1, Captive portal with local user manager.



  • Anyone/everyone who's seeing this, what's in your /var/log/lighttpd.error.log around the time it happens? On Abdsalem's box, fastcgi is crashing.



  • mine , i dont know what it is but captive portal status stopped

    2012-12-31 18:16:36: (mod_fastcgi.c.3282) child exited, pid: 23026 status: 0
    2012-12-31 18:16:36: (mod_fastcgi.c.3329) response not received, request sent: 1126 on socket: unix:/tmp/php-fastcgi.socket-3 for /index.php?redirurl=/index.php?redirurl=http%3A%2F%2Fimg.rnudah.comthumbs%2F95%2F9521154049.jpg, closing connection
    2012-12-31 18:16:36: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 30512 socket: unix:/tmp/php-fastcgi.socket-3
    2012-12-31 18:16:36: (mod_fastcgi.c.3329) response not received, request sent: 893 on socket: unix:/tmp/php-fastcgi.socket-3 for /index.php?redirurl=/thumbs/00/0071075068.jpg, closing connection
    2012-12-31 18:16:36: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 30512 socket: unix:/tmp/php-fastcgi.socket-3
    2012-12-31 18:16:36: (mod_fastcgi.c.3329) response not received, request sent: 2161 on socket: unix:/tmp/php-fastcgi.socket-3 for /index.php?redirurl=/adj/mudah.my.vehicles/adview/cars;gc1=en;gc2=ca-scm-mudah_js;gc3=js;gc4=off;gc5=image_flash;gc6=1;gc7=300x250;gc8=;kw=bmw%2Bm3%2Be46;cg=1020;tile=2;sz=300x250;region=9;car=BMW325i;cartype=sedan;threshold1=low;threshold2=low;threshold1_rec=low;threshold2_rec=low;b1=50000;subj=BMW318iE46LASTBATCH-M-SPORT-LIFESTYLEMODEL;adv=changsangmotorssdnbhd;brand=;adtype=s;itemcondition=used;gender=;regdate=2005;ord=997121231181964?, closing connection
    2012-12-31 18:16:36: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 30512 socket: unix:/tmp/php-fastcgi.socket-3
    2012-12-31 18:16:36: (mod_fastcgi.c.3329) response not received, request sent: 1131 on socket: unix:/tmp/php-fastcgi.socket-3 for /index.php?redirurl=/index.php?redirurl=http%3A%2F%2Fimg.rnudah.comimages%2F00%2F0068691096.jpg, closing connection
    2012-12-31 18:52:12: (request.c.1133) GET/HEAD with content-length -> 400
    2012-12-31 18:52:43: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-3
    2012-12-31 18:52:43: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    2012-12-31 18:56:16: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-0
    2012-12-31 18:56:16: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 4
    2012-12-31 18:56:34: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-2
    2012-12-31 18:56:34: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 2
    2012-12-31 19:07:46: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-3
    2012-12-31 19:07:46: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 2
    2012-12-31 19:12:04: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 22378 socket: unix:/tmp/php-fastcgi.socket-1
    2012-12-31 19:12:04: (mod_fastcgi.c.3329) response not received, request sent: 1081 on socket: unix:/tmp/php-fastcgi.socket-1 for /index.php?redirurl=/index.php?redirurl=http%3A%2F%2Fmy-cdn.effectivemeasure.netem.js, closing connection
    2012-12-31 19:12:40: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    2012-12-31 19:12:40: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 3



  • Can you please post what architecture you are on?



  • Pfsense 2.02 in virtualbox Xp host
    Squid ,Squidguard,Lightsquid,Unbound



  • @cmb:

    Anyone/everyone who's seeing this, what's in your /var/log/lighttpd.error.log around the time it happens? On Abdsalem's box, fastcgi is crashing.

    Hi I'm new here.

    I'd like to report the same issue after upgrading from 2.0.1 to 2.0.2

    I'm on i386

    tail -30 /var/log/lighttpd.error.log

    2013-01-01 21:18:56: (mod_fastcgi.c.3329) response not received, request sent: 927 on socket: unix:/tmp/php-fastcgi.socket-1 for /graph.php?ifnum=wan&ifname=WAN&timeint=3&initdelay=4, closing connection
    2013-01-01 21:18:56: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 5258 socket: unix:/tmp/php-fastcgi.socket-1
    2013-01-01 21:18:56: (mod_fastcgi.c.3329) response not received, request sent: 927 on socket: unix:/tmp/php-fastcgi.socket-1 for /graph.php?ifnum=wan&ifname=WAN&timeint=3&initdelay=4, closing connection
    2013-01-01 21:18:56: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 5258 socket: unix:/tmp/php-fastcgi.socket-1
    2013-01-01 21:18:56: (mod_fastcgi.c.3329) response not received, request sent: 927 on socket: unix:/tmp/php-fastcgi.socket-1 for /graph.php?ifnum=wan&ifname=WAN&timeint=3&initdelay=4, closing connection
    2013-01-01 21:18:56: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 5258 socket: unix:/tmp/php-fastcgi.socket-1
    2013-01-01 21:18:56: (mod_fastcgi.c.3329) response not received, request sent: 927 on socket: unix:/tmp/php-fastcgi.socket-1 for /graph.php?ifnum=wan&ifname=WAN&timeint=3&initdelay=4, closing connection
    2013-01-01 21:18:56: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 5258 socket: unix:/tmp/php-fastcgi.socket-1
    2013-01-01 21:18:56: (mod_fastcgi.c.3329) response not received, request sent: 927 on socket: unix:/tmp/php-fastcgi.socket-1 for /graph.php?ifnum=wan&ifname=WAN&timeint=3&initdelay=4, closing connection
    2013-01-01 21:18:56: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 5258 socket: unix:/tmp/php-fastcgi.socket-1
    2013-01-01 21:18:56: (mod_fastcgi.c.3329) response not received, request sent: 927 on socket: unix:/tmp/php-fastcgi.socket-1 for /graph.php?ifnum=wan&ifname=WAN&timeint=3&initdelay=4, closing connection
    2013-01-01 21:18:57: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    2013-01-01 21:18:57: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    2013-01-01 21:19:06: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    2013-01-01 21:19:06: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    2013-01-01 21:19:10: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    2013-01-01 21:19:10: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    2013-01-01 21:19:18: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    2013-01-01 21:19:18: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    2013-01-01 21:19:22: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    2013-01-01 21:19:22: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    2013-01-01 21:19:29: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    2013-01-01 21:19:29: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    2013-01-01 21:19:37: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    2013-01-01 21:19:37: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    2013-01-01 22:15:03: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    2013-01-01 22:15:03: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    2013-01-01 22:30:44: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 27642 socket: unix:/tmp/php-fastcgi.socket-1
    2013-01-01 22:30:44: (mod_fastcgi.c.3282) child exited, pid: 27642 status: 0
    2013-01-01 22:30:44: (mod_fastcgi.c.3329) response not received, request sent: 1190 on socket: unix:/tmp/php-fastcgi.socket-1 for /index.php?redirurl=/index.php?redirurl=http%3A%2F%2Fax.init.itunes.apple.combag.xml%3Fix%3D2, closing connection

    /usr/local/sbin/lighttpd -f /var/etc/lighty-CaptivePortal.conf

    2013-01-01 22:45:50: (network.c.385) can't bind to port:  8000 Address already in use

    netstat -a

    Active Internet connections (including servers)
    Proto Recv-Q Send-Q  Local Address          Foreign Address      (state)
    tcp4      0      0 wilsonfw1.http        David_MBP2010.56005    ESTABLISHED
    tcp4      0      0 wilsonfw1.2189        192.168.10.15.4876    TIME_WAIT
    tcp4      0      0 wilsonfw1.2189        192.168.10.15.4869    TIME_WAIT
    tcp4      0      0 wilsonfw1.rsh-spx      David_MBP2010.54588    ESTABLISHED
    tcp4      0      0 *.8000                .                    LISTEN
    tcp4      0      0 *.mdqs                .                    LISTEN
    tcp6      0      0 *.mdqs                .                    LISTEN
    tcp4      0      0 *.2189                .                    LISTEN
    tcp6      0      0 *.domain              .                    LISTEN
    tcp4      0      0 *.domain              .                    LISTEN
    tcp4      0      0 *.http                .                    LISTEN
    tcp4      0      0 *.rsh-spx              .                    LISTEN
    tcp6      0      0 *.rsh-spx              .                    LISTEN
    udp6      0      0 *.20286                .                   
    udp4      0      0 *.60147                .                   
    udp4      0      0 .                    .                   
    udp4      0      0 localhost.tftp-proxy  .                   
    udp6      0      0 *.15825                .                   
    udp4      0      0 *.47275                .                   
    udp6      0      0 *.9454                .                   
    udp4      0      0 *.56663                .                   
    udp4      0      0 .                    .                   
    udp6      0      0 *.58666                .                   
    udp4      0      0 *.15424                .                   
    udp6      0      0 *.16852                .                   
    udp4      0      0 *.8334                .                   
    udp4      0      0 wilsonfw1.5351        .                   
    udp4      0      0 wilsonfw1.35170        .                   
    udp4      0      0 *.1900                .                   
    udp4      0      0 *.router              .                   
    udp6      0      0 ::1.ntp                .                   
    udp4      0      0 localhost.ntp          .                   
    udp6      0      0 fe80:4::2b0:d0ff.ntp  .                   
    udp4      0      0 wilsonfw1.ntp          .                   
    udp6      0      0 *.ntp                  .                   
    udp4      0      0 *.ntp                  .                   
    udp6      0      0 *.domain              .                   
    udp4      0      0 *.domain              .                   
    udp4      0      0 *.bootps              .                   
    udp6      0      0 *.7322                .                   
    udp4      0      0 *.59747                .                   
    udp4      0      0 *.syslog              .                   
    udp6      0      0 .syslog              .                   
    ip 4      0      0 .                    .                   
    ip 4      0      0 .                    .                   
    ip 4      0      0 .                    .                   
    icm4      0      0 .                    .                   
    icm4      0      0 .                    .                   
    icm4      0      0 203-97-236-202.c.
        .                   
    ip64      0      0 .                    .                   
    ip64      0      0 .                    .                   
    ip64      0      0 .                    .

    • David


  • I'm running 64bit version full install in a vm.

    Same problem a moment ago, so I dropped to the console and killed the process running lightys captive portal instance and then restarted the captive portal from the gui and it started up fine, I doubled checked lightys error log and found this.

    2012-12-31 22:19:28: (log.c.166) server started
    2012-12-31 22:19:28: (server.c.987) WARNING: unknown config-key: evasive.max-conns-per-ip (ignored)

    I know its just a warning but I have "Maximum concurrent connections" set to a value of "6" in the captive portal gui, I removed this value, restarted the captive portal and the warning went away, I dont know if this is related but I thought I'd mention it.



  • Can you please gitsync to RELENG_2_0 branch and see if that fixes for you?



  • @ermal:

    Can you please gitsync to RELENG_2_0 branch and see if that fixes for you?

    Hello.  More than happy to do so… err how?

    • David


  • @ermal:

    Can you please gitsync to RELENG_2_0 branch and see if that fixes for you?

    OK. found this… http://doc.pfsense.org/index.php/Updating_pfSense_code_between_snapshots
    Actioning now.

    • David


  • @ermal:

    Can you please gitsync to RELENG_2_0 branch and see if that fixes for you?

    Captive portal is running.

    The following messages are in the error logs:

    Jan 3 08:12:19 lighttpd[60409]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:12:19 lighttpd[60409]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:12:19 lighttpd[60409]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:12:19 lighttpd[60409]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:10:13 lighttpd[60409]: (mod_fastcgi.c.3329) response not received, request sent: 927 on socket: unix:/tmp/php-fastcgi.socket-1 for /graph.php?ifnum=wan&ifname=WAN&timeint=3&initdelay=4, closing connection
    Jan 3 08:10:13 lighttpd[60409]: (mod_fastcgi.c.3329) response not received, request sent: 927 on socket: unix:/tmp/php-fastcgi.socket-1 for /graph.php?ifnum=wan&ifname=WAN&timeint=3&initdelay=4, closing connection
    Jan 3 08:10:12 lighttpd[60409]: (mod_fastcgi.c.3282) child exited, pid: 35644 status: 0
    Jan 3 08:10:12 lighttpd[60409]: (mod_fastcgi.c.3282) child exited, pid: 35644 status: 0
    Jan 3 08:10:12 lighttpd[60409]: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 35644 socket: unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:10:12 lighttpd[60409]: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 35644 socket: unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:10:08 lighttpd[60409]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 2
    Jan 3 08:10:08 lighttpd[60409]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 2
    Jan 3 08:10:08 lighttpd[60409]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-0
    Jan 3 08:10:08 lighttpd[60409]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-0
    Jan 3 08:10:07 lighttpd[60409]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:10:07 lighttpd[60409]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:10:07 lighttpd[60409]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:10:07 lighttpd[60409]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:10:01 lighttpd[60409]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:10:01 lighttpd[60409]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:10:01 lighttpd[60409]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:10:01 lighttpd[60409]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:09:42 check_reload_status: Reloading filter
    Jan 3 08:09:42 lighttpd[17609]: (log.c.166) server started
    Jan 3 08:09:42 lighttpd[17609]: (log.c.166) server started

    These errors are continuing…

    Jan 3 08:14:59 lighttpd[60409]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:14:59 lighttpd[60409]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:14:59 lighttpd[60409]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:14:59 lighttpd[60409]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:14:32 lighttpd[17609]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:14:32 lighttpd[17609]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:14:32 lighttpd[17609]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:14:32 lighttpd[17609]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:14:18 lighttpd[60409]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 2
    Jan 3 08:14:18 lighttpd[60409]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 2
    Jan 3 08:14:18 lighttpd[60409]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:14:18 lighttpd[60409]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1

    I can't validate at the moment if the captive Portal is working….

    I removed an allowed host from the portal.
    It could still access the internet.
    I restarted the captive portal... and now it's failing again.

    Jan 3 08:20:43 lighttpd[60409]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 1 load: 1
    Jan 3 08:20:43 lighttpd[60409]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 1 load: 1
    Jan 3 08:20:43 lighttpd[60409]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-0
    Jan 3 08:20:43 lighttpd[60409]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-0
    Jan 3 08:20:43 lighttpd[60409]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:20:43 lighttpd[60409]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:20:43 lighttpd[60409]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:20:43 lighttpd[60409]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:20:22 lighttpd[60409]: (mod_fastcgi.c.2760) fcgi-server re-enabled: 0 /tmp/php-fastcgi.socket
    Jan 3 08:20:22 lighttpd[60409]: (mod_fastcgi.c.2760) fcgi-server re-enabled: 0 /tmp/php-fastcgi.socket
    Jan 3 08:20:20 php: /status_services.php: The command '/usr/local/sbin/lighttpd -f /var/etc/lighty-CaptivePortal.conf' returned exit code '255', the output was '2013-01-03 08:20:20: (network.c.385) can't bind to port: 8000 Address already in use'

    Next step - reboot firewall.

    Rebooted- home page says it's NOT running, then says it is running…

    Jan 3 08:30:26 lighttpd[31743]: (mod_fastcgi.c.3329) response not received, request sent: 927 on socket: unix:/tmp/php-fastcgi.socket-1 for /graph.php?ifnum=wan&ifname=WAN&timeint=3&initdelay=4, closing connection
    Jan 3 08:30:26 lighttpd[31743]: (mod_fastcgi.c.3329) response not received, request sent: 927 on socket: unix:/tmp/php-fastcgi.socket-1 for /graph.php?ifnum=wan&ifname=WAN&timeint=3&initdelay=4, closing connection
    Jan 3 08:30:26 lighttpd[31743]: (mod_fastcgi.c.3282) child exited, pid: 32580 status: 0
    Jan 3 08:30:26 lighttpd[31743]: (mod_fastcgi.c.3282) child exited, pid: 32580 status: 0
    Jan 3 08:30:26 lighttpd[31743]: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 32580 socket: unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:30:26 lighttpd[31743]: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 32580 socket: unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:26:55 apinger: rrdtool respawning too fast, waiting 300s.
    Jan 3 08:26:50 lighttpd[52016]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:26:50 lighttpd[52016]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:26:50 lighttpd[52016]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:26:50 lighttpd[52016]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:26:35 lighttpd[52016]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:26:35 lighttpd[52016]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:26:35 lighttpd[52016]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:26:35 lighttpd[52016]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:26:35 lighttpd[52016]: (mod_fastcgi.c.3329) response not received, request sent: 669 on socket: unix:/tmp/php-fastcgi.socket-1 for /index.php?redirurl=/configurations/pep/pipeline/pipeline2.html, closing connection
    Jan 3 08:26:35 lighttpd[52016]: (mod_fastcgi.c.3329) response not received, request sent: 669 on socket: unix:/tmp/php-fastcgi.socket-1 for /index.php?redirurl=/configurations/pep/pipeline/pipeline2.html, closing connection
    Jan 3 08:26:35 lighttpd[52016]: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 35226 socket: unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:26:35 lighttpd[52016]: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 35226 socket: unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:26:34 lighttpd[52016]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:26:34 lighttpd[52016]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:26:34 lighttpd[52016]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:26:34 lighttpd[52016]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:26:27 lighttpd[52016]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:26:27 lighttpd[52016]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 08:26:27 lighttpd[52016]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:26:27 lighttpd[52016]: (mod_fastcgi.c.1732) connect failed: Connection refused on unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:26:27 lighttpd[52016]: (mod_fastcgi.c.3329) response not received, request sent: 3060 on socket: unix:/tmp/php-fastcgi.socket-1 for /index.php?redirurl=/index.php?redirurl=http%3A%2F%2Fax.init.itunes.apple.com%2Fbag.xml%3Fix%3D2, closing connection
    Jan 3 08:26:27 lighttpd[52016]: (mod_fastcgi.c.3329) response not received, request sent: 3060 on socket: unix:/tmp/php-fastcgi.socket-1 for /index.php?redirurl=/index.php?redirurl=http%3A%2F%2Fax.init.itunes.apple.com%2Fbag.xml%3Fix%3D2, closing connection
    Jan 3 08:26:27 lighttpd[52016]: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 0 socket: unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:26:27 lighttpd[52016]: (mod_fastcgi.c.2543) unexpected end-of-file (perhaps the fastcgi process died): pid: 0 socket: unix:/tmp/php-fastcgi.socket-1
    Jan 3 08:26:12 check_reload_status: Reloading filter
    Jan 3 08:26:12 login: login on ttyv0 as root
    Jan 3 08:26:09 php: : IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
    Jan 3 08:26:09 bandwidthd: Packet Encoding: Ethernet
    Jan 3 08:26:09 bandwidthd: Opening xl0
    Jan 3 08:26:09 bandwidthd: Monitoring subnet 203.97.236.0 with netmask 203.97.236.0
    Jan 3 08:26:09 bandwidthd: Monitoring subnet 192.168.250.0 with netmask 192.168.250.0
    Jan 3 08:26:09 bandwidthd: Monitoring subnet 192.168.10.0 with netmask 192.168.10.0
    Jan 3 08:26:09 bandwidthd: Monitoring subnet 192.168.10.0 with netmask 192.168.10.0
    Jan 3 08:26:04 php: : The command '/usr/local/etc/rc.d/bandwidthd.sh stop' returned exit code '1', the output was 'No matching processes were found'
    Jan 3 08:26:04 php: : The command '/usr/local/etc/rc.d/bandwidthd.sh stop' returned exit code '1', the output was 'No matching processes were found'
    Jan 3 08:26:04 kernel: xl0: promiscuous mode enabled
    Jan 3 08:26:02 php: : The command '/usr/local/etc/rc.d/darkstat.sh stop' returned exit code '1', the output was 'No matching processes were found'
    Jan 3 08:25:59 php: : Restarting/Starting all packages.
    Jan 3 08:25:56 miniupnpd[63000]: Listening for NAT-PMP traffic on port 5351
    Jan 3 08:25:56 miniupnpd[63000]: Listening for NAT-PMP traffic on port 5351
    Jan 3 08:25:56 miniupnpd[63000]: HTTP listening on port 2189
    Jan 3 08:25:56 miniupnpd[63000]: HTTP listening on port 2189
    Jan 3 08:25:56 php: : miniupnpd: Starting service on interface: lan
    Jan 3 08:25:55 apinger: Error while feeding rrdtool: Broken pipe
    Jan 3 08:25:55 php: : Creating rrd update script
    Jan 3 08:25:49 check_reload_status: Restarting ipsec tunnels
    Jan 3 08:25:46 lighttpd[52016]: (log.c.166) server started
    Jan 3 08:25:46 lighttpd[52016]: (log.c.166) server started
    Jan 3 08:25:29 kernel: ipfw2 (+ipv6) initialized, divert loadable, nat loadable, rule-based forwarding enabled, default to accept, logging disabled
    Jan 3 08:25:23 dnsmasq[42232]: read /etc/hosts - 59 addresses
    Jan 3 08:25:22 check_reload_status: Updating all dyndns
    Jan 3 08:25:22 dnsmasq[42232]: ignoring nameserver 127.0.0.1 - local interface
    Jan 3 08:25:22 dnsmasq[42232]: ignoring nameserver 127.0.0.1 - local interface
    Jan 3 08:25:22 dnsmasq[42232]: using nameserver 203.97.78.43#53
    Jan 3 08:25:22 dnsmasq[42232]: using nameserver 203.97.78.44#53
    Jan 3 08:25:22 dnsmasq[42232]: reading /etc/resolv.conf
    Jan 3 08:25:22 dnsmasq[42232]: compile time options: IPv6 GNU-getopt no-DBus i18n IDN DHCP DHCPv6 no-Lua TFTP no-conntrack
    Jan 3 08:25:22 dnsmasq[42232]: started, version 2.63 cachesize 10000
    Jan 3 08:25:21 dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory.
    Jan 3 08:25:16 ntpdate[38757]: step time server 202.78.240.38 offset 1.736489 sec
    Jan 3 08:25:06 dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory.
    Jan 3 08:25:01 dhcpd: For info, please visit https://www.isc.org/software/dhcp/
    Jan 3 08:25:01 dhcpd: All rights reserved.
    Jan 3 08:25:01 dhcpd: Copyright 2004-2012 Internet Systems Consortium.
    Jan 3 08:25:01 dhcpd: Internet Systems Consortium DHCP Server 4.2.4-P1
    Jan 3 08:25:01 dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory.
    Jan 3 08:25:00 dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory.
    Jan 3 08:24:59 php: : ROUTING: setting default route to 203.97.236.1
    Jan 3 08:24:58 lighttpd[31743]: (log.c.166) server started
    Jan 3 08:24:58 lighttpd[31743]: (log.c.166) server started
    Jan 3 08:24:55 apinger: Starting Alarm Pinger, apinger(17845)
    Jan 3 08:24:54 sshlockout[16863]: sshlockout/webConfigurator v3.0 starting up
    Jan 3 08:24:54 sshd[16759]: Server listening on 0.0.0.0 port 222.
    Jan 3 08:24:54 sshd[16759]: Server listening on :: port 222.
    Jan 3 08:24:53 kernel: load_dn_sched dn_sched PRIO loaded
    Jan 3 08:24:53 kernel: load_dn_sched dn_sched WF2Q+ loaded
    Jan 3 08:24:53 kernel: load_dn_sched dn_sched RR loaded
    Jan 3 08:24:53 kernel: load_dn_sched dn_sched QFQ loaded
    Jan 3 08:24:53 kernel: load_dn_sched dn_sched FIFO loaded
    Jan 3 08:24:53 check_reload_status: Linkup starting rl2

    testing on device that I removed the host for… it requested authentication and then proceeded to the page for a successful load.

    So it's working... with issues?



  • I've also applied the updated with gitsync after taking a snapshot of my vm, JIC.

    Also Ermal thanks for the mod_evasive/max concurrent connections fix , it is now working….as well as the bug with traffic graph reported on another post.

    Log in reverse order.

    Jan 3 05:08:58 dhclient: RENEW
    Jan 3 05:08:17 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:17 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:17 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:17 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:16 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:16 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:12 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:12 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:12 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:12 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:09 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:09 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:09 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:09 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:09 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:09 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:09 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:09 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:08 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:08 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:07 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:07 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:07 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:08:07 lighttpd[25142]: (mod_evasive.c.183) 10.0.0.228 turned away. Too many connections.
    Jan 3 05:07:14 dnsmasq[32508]: read /etc/hosts - 48 addresses
    Jan 3 05:04:47 dnsmasq[32508]: read /etc/hosts - 48 addresses
    Jan 3 05:01:54 dnsmasq[32508]: read /etc/hosts - 48 addresses
    Jan 3 04:59:36 dnsmasq[32508]: read /etc/hosts - 48 addresses
    Jan 3 04:58:52 dnsmasq[32508]: read /etc/hosts - 48 addresses
    Jan 3 04:55:18 dnsmasq[32508]: read /etc/hosts - 48 addresses
    Jan 3 04:54:18 check_reload_status: Reloading filter
    Jan 3 04:54:18 lighttpd[25142]: (log.c.166) server started
    Jan 3 04:54:18 lighttpd[25142]: (log.c.166) server started
    Jan 3 04:54:15 kernel: ipfw2 (+ipv6) initialized, divert loadable, nat loadable, rule-based forwarding enabled, default to accept, logging disabled
    Jan 3 04:54:14 check_reload_status: Syncing firewall
    Jan 3 04:53:51 lighttpd[11896]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 04:53:51 lighttpd[11896]: (mod_fastcgi.c.3002) backend died; we'll disable it for 1 seconds and send the request to another backend instead: reconnects: 0 load: 1
    Jan 3 04:53:51 lighttpd[11896]: (mod_fastcgi.c.1732) connect failed: No such file or directory on unix:/tmp/php-fastcgi.socket-1
    Jan 3 04:53:51 lighttpd[11896]: (mod_fastcgi.c.1732) connect failed: No such file or directory on unix:/tmp/php-fastcgi.socket-1
    Jan 3 04:53:33 lighttpd[13787]: (server.c.1546) server stopped by UID = 0 PID = 2939
    Jan 3 04:53:33 lighttpd[13787]: (server.c.1546) server stopped by UID = 0 PID = 2939
    Jan 3 04:52:52 kernel: IP firewall unloaded
    Jan 3 04:52:52 check_reload_status: Reloading filter
    Jan 3 04:52:52 minicron: (/etc/rc.prunecaptiveportal) terminated by signal 15 (Terminated: 15)
    Jan 3 04:52:52 check_reload_status: Syncing firewall
    Jan 3 04:51:00 apinger: Error while feeding rrdtool: Broken pipe
    Jan 3 04:50:55 php[14668]: /services_captiveportal.php: The command '/usr/local/sbin/lighttpd -f /var/etc/lighty-CaptivePortal.conf' returned exit code '255', the output was '2013-01-03 04:50:55: (network.c.385) can't bind to port: 8000 Address already in use'
    Jan 3 04:50:54 minicron: (/etc/rc.prunecaptiveportal) terminated by signal 15 (Terminated: 15)
    Jan 3 04:50:50 check_reload_status: Reloading filter
    Jan 3 04:50:50 php[15003]: /services_captiveportal.php: The command '/usr/local/sbin/lighttpd -f /var/etc/lighty-CaptivePortal.conf' returned exit code '255', the output was '2013-01-03 04:50:50: (network.c.385) can't bind to port: 8000 Address already in use'
    Jan 3 04:50:47 minicron: (/etc/rc.prunecaptiveportal) terminated by signal 15 (Terminated: 15)
    Jan 3 04:50:47 check_reload_status: Syncing firewall
    Jan 3 04:50:10 php: : Creating rrd update script
    Jan 3 04:50:10 lighttpd[13787]: (log.c.166) server started
    Jan 3 04:50:10 lighttpd[13787]: (log.c.166) server started
    Jan 3 04:50:09 lighttpd[11896]: (log.c.166) server started
    Jan 3 04:50:09 lighttpd[11896]: (log.c.166) server started
    Jan 3 04:50:06 check_reload_status: webConfigurator restart in progress
    Jan 3 04:50:01 php: : Start Configuration upgrade at 04:50:01, set execution timeout to 15 minutes

    Ahh and thanks outputing lightys error log to diag_logs, Ill report back if there are any problems.



  • I put some more fixes in there so just gitsync again.



  • @ermal:

    I put some more fixes in there so just gitsync again.

    So far so good.

    Something was horribly wrong after the update was applied. Responses to the web interface virtually stopped… so I rebooted.

    Testing with a single device has been successful. Software, after a few minutes, appears stable according to the logs.

    • David

    Jan 4 07:51:11 apinger: rrdtool respawning too fast, waiting 300s.
    Jan 4 07:50:39 login: login on ttyv0 as root
    Jan 4 07:50:38 check_reload_status: Reloading filter
    Jan 4 07:50:32 bandwidthd: Packet Encoding: Ethernet
    Jan 4 07:50:32 php: : IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
    Jan 4 07:50:32 bandwidthd: Opening xl0
    Jan 4 07:50:32 bandwidthd: Monitoring subnet 203.97.236.0 with netmask 203.97.236.0
    Jan 4 07:50:32 bandwidthd: Monitoring subnet 192.168.250.0 with netmask 192.168.250.0
    Jan 4 07:50:32 bandwidthd: Monitoring subnet 192.168.10.0 with netmask 192.168.10.0
    Jan 4 07:50:32 bandwidthd: Monitoring subnet 192.168.10.0 with netmask 192.168.10.0
    Jan 4 07:50:27 php: : The command '/usr/local/etc/rc.d/bandwidthd.sh stop' returned exit code '1', the output was 'No matching processes were found'
    Jan 4 07:50:27 php: : The command '/usr/local/etc/rc.d/bandwidthd.sh stop' returned exit code '1', the output was 'No matching processes were found'
    Jan 4 07:50:27 kernel: xl0: promiscuous mode enabled
    Jan 4 07:50:25 php: : The command '/usr/local/etc/rc.d/darkstat.sh stop' returned exit code '1', the output was 'No matching processes were found'
    Jan 4 07:50:21 php: : Restarting/Starting all packages.
    Jan 4 07:50:11 apinger: Error while feeding rrdtool: Broken pipe
    Jan 4 07:50:10 miniupnpd[1738]: Listening for NAT-PMP traffic on port 5351
    Jan 4 07:50:10 miniupnpd[1738]: Listening for NAT-PMP traffic on port 5351
    Jan 4 07:50:10 miniupnpd[1738]: HTTP listening on port 2189
    Jan 4 07:50:10 miniupnpd[1738]: HTTP listening on port 2189
    Jan 4 07:50:10 php: : miniupnpd: Starting service on interface: lan
    Jan 4 07:50:08 php: : Creating rrd update script
    Jan 4 07:50:02 check_reload_status: Restarting ipsec tunnels
    Jan 4 07:49:59 lighttpd[51111]: (log.c.166) server started
    Jan 4 07:49:59 lighttpd[51111]: (log.c.166) server started
    Jan 4 07:49:39 kernel: ipfw2 (+ipv6) initialized, divert loadable, nat loadable, rule-based forwarding enabled, default to accept, logging disabled
    Jan 4 07:49:26 ntpdate[37661]: step time server 209.167.68.100 offset 0.929602 sec
    Jan 4 07:49:18 dnsmasq[40770]: read /etc/hosts - 60 addresses
    Jan 4 07:49:18 dnsmasq[40770]: ignoring nameserver 127.0.0.1 - local interface
    Jan 4 07:49:18 dnsmasq[40770]: ignoring nameserver 127.0.0.1 - local interface
    Jan 4 07:49:18 dnsmasq[40770]: using nameserver 203.97.78.43#53
    Jan 4 07:49:18 dnsmasq[40770]: using nameserver 203.97.78.44#53
    Jan 4 07:49:18 dnsmasq[40770]: reading /etc/resolv.conf
    Jan 4 07:49:18 dnsmasq[40770]: compile time options: IPv6 GNU-getopt no-DBus i18n IDN DHCP DHCPv6 no-Lua TFTP no-conntrack
    Jan 4 07:49:18 dnsmasq[40770]: started, version 2.63 cachesize 10000
    Jan 4 07:49:18 check_reload_status: Updating all dyndns
    Jan 4 07:49:17 dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory.
    Jan 4 07:49:17 dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory.
    Jan 4 07:49:17 dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory.
    Jan 4 07:49:17 dhcpd: For info, please visit https://www.isc.org/software/dhcp/
    Jan 4 07:49:17 dhcpd: All rights reserved.
    Jan 4 07:49:17 dhcpd: Copyright 2004-2012 Internet Systems Consortium.
    Jan 4 07:49:17 dhcpd: Internet Systems Consortium DHCP Server 4.2.4-P1
    Jan 4 07:49:17 dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory.
    Jan 4 07:49:14 php: : ROUTING: setting default route to 203.97.236.1
    Jan 4 07:49:14 lighttpd[29910]: (log.c.166) server started
    Jan 4 07:49:14 lighttpd[29910]: (log.c.166) server started
    Jan 4 07:49:11 apinger: Starting Alarm Pinger, apinger(17425)
    Jan 4 07:49:10 sshlockout[16498]: sshlockout/webConfigurator v3.0 starting up
    Jan 4 07:49:10 sshd[16201]: Server listening on 0.0.0.0 port 222.
    Jan 4 07:49:10 sshd[16201]: Server listening on :: port 222.



  • I havent gitsynced the latest updates since the early hours of this morning but so far so good, the original error of captive portal crashing seems to be fixed, as well as some other minor bugs, the redirected lighty error log also reports no problems.

    Big thanks to the devs and pfsensers!



  • Hi I am having the same issue, upgraded from 2.0.1 (i386) to 2.0.2 in the services tap captive portal appears down. Interestingly I use radius and openldap for the username and passwords on a separate computer. When a user types in a username and password they get an error saying that page could not be reached, but then if they close the browser and open it they have been authenticated by captive portal and all is working. I am also using esx 4, I use squid (as transparent proxy) and squidguard and a wpad file to auto configure the browser. It all worked fine before the upgrade.



  • Please gitsync to latest changes i think the root cause of this has been fixed now.



  • yep did this and after a reboot everything works again, thanks for your help really appreciated.



  • @ermal:

    Please gitsync to latest changes i think the root cause of this has been fixed now.

    I updated (sync'd) again. Everything has remained stable over night.

    • David


  • I did a gitsync the other day and that fixed the captive portal being stopped issue. What I've noticed since though is that clients have to either renew their IP or turn WiFi Off/On to be redirected to the captive portal after the 1 hour time out. DHCP default and maximum lease times are not set in the configuration so I'm presuming they are 720 seconds and 86400 seconds respectively, both definitely longer than the time out.



  • Same here >:(…upgraded and no more capitve po



  • @wwifi1944:

    Same here >:(…upgraded and no more capitve po

    gitsync as described here and it will be fixed.



  • Hi everyone,

    I confirm with the fix is working.

    But i have some logs that i don't understand like :

    lighttpd[34598]: (mod_fastcgi.c.2676) FastCGI-stderr: ALERT - ASCII-NUL chars not allowed within request variables - dropped variable 'redirurl' (attacker '172.16.1.37', file '/usr/local/captiveportal/index.php')

    lighttpd[34598]: (mod_fastcgi.c.2676) FastCGI-stderr: ALERT - ASCII-NUL chars not allowed within request variables - dropped variable 'sessionkey' (attacker '172.16.1.141', file '/usr/local/captiveportal/index.php')

    lighttpd[34598]: (connections.c.137) (warning) close: 73 Connection reset by peer

    Best regards.
    Myke.



  • Using 2.02 in a production environment so I am reluctant to do a gitsync. I may come in this weekend and give it a try.

    Interesting that although under service status the captiveportal service says Stopped captive portal is running and users are being asked to login.



  • Hello.

    I have the "same issue" Since I upgrade my installation, captive portal don't works as expected. I have had to disable it.

    My problem is that the ip roules stop working suddenly.

    f.e. my rule "both any->10.2.0.0/16" stop working and the only way to work around was enable certains IPs on the captive portal (so they have access to internet too, and i don't want this).

    Thanks!

    Now i'm gitsyncing.. I'll try after



  • Hi after gitsyncing and going to 2.0.3 I had a number of other issues, such as under heavy load the firewall blocking everything with nothing entered into the syslog. we have 800 captive portal users and everything was working well in 2.0.1 . I have reverted back to 2.0.1 . The main reason was due to the crashing and the fact that the web gui became really slow, and crashed alot. I run 2 other pfsense devices and I have not gone back to 2.0.2 on them as they do not use captive portal. On all the devices that I have upgraded i have found the performance of the webgiu gets much worse after the upgrade with me having to remove the status widget from the dashboard to make some small improvements.



  • Web GUI seems very fast with 2.02. Have not gitsynced yet. Is there a 2.0.3 release? I have not seen it.



  • when you gitsync you will goto 2.0.3 pre release



  • he is right is there any workaround, a lot of error message coming out. Also Captive portal is not working.

    @debremarkos:

    when you gitsync you will goto 2.0.3 pre release



  • The latest 2.0.3 is stable from our testing.
    Can you try because at the time there were some changes being done.
    Now it is marked as stable on our side!



  • heres the error i got

    Jan 31 19:57:20 	lighttpd[21213]: (connections.c.305) SSL: 1 error:140760FC:SSL routines:SSL23_GET_CLIENT_HELLO:unknown protocol
    Jan 31 19:57:20 	lighttpd[21213]: (connections.c.305) SSL: 1 error:140760FC:SSL routines:SSL23_GET_CLIENT_HELLO:unknown protocol
    

    @ermal:

    The latest 2.0.3 is stable from our testing.
    Can you try because at the time there were some changes being done.
    Now it is marked as stable on our side!



  • yesterday i've deployed 2.0.3 with a ssl cert from startssl & Radius auth on a Win2K8r2

    i've seen that too:

    Jan 31 19:57:20 	lighttpd[21213]: (connections.c.305) SSL: 1 error:140760FC:SSL routines:SSL23_GET_CLIENT_HELLO:unknown protocol
    Jan 31 19:57:20 	lighttpd[21213]: (connections.c.305) SSL: 1 error:140760FC:SSL routines:SSL23_GET_CLIENT_HELLO:unknown protocol
    

    doesn't seem to affect the portal … i've had +40 portal users all day without complaints



  • Running latest snapshot of PRERELEASE-2.0.3 (31/01/2013)

    I can also confirm what the last 2 posters have reported, though it doesnt seem to affect the CP users.

    I am also seeing a lot of the following.

    Jan 31 20:23:57 lighttpd[18696]: (connections.c.137) (warning) close: 25 Connection reset by peer
    Jan 31 20:23:57 lighttpd[18696]: (connections.c.137) (warning) close: 25 Connection reset by peer

    Jan 31 20:02:55 lighttpd[18696]: (request.c.1133) GET/HEAD with content-length -> 400
    Jan 31 20:02:55 lighttpd[18696]: (request.c.1133) GET/HEAD with content-length -> 400

    Jan 31 19:56:03 lighttpd[18696]: (mod_fastcgi.c.2676) FastCGI-stderr: ALERT - ASCII-NUL chars not allowed within request variables - dropped variable 'redirurl' (attacker '10.0.0.109', file '/usr/local/captiveportal/index.php')
    Jan 31 19:56:03 lighttpd[18696]: (mod_fastcgi.c.2676) FastCGI-stderr: ALERT - ASCII-NUL chars not allowed within request variables - dropped variable 'redirurl' (attacker '10.0.0.109', file '/usr/local/captiveportal/index.php')

    Jan 31 17:55:50 lighttpd[18696]: (mod_fastcgi.c.2676) FastCGI-stderr: ALERT - ASCII-NUL chars not allowed within request variables - dropped variable 'info_hash' (attacker '10.0.0.78', file '/usr/local/captiveportal/index.php')
    Jan 31 17:55:50 lighttpd[18696]: (mod_fastcgi.c.2676) FastCGI-stderr: ALERT - ASCII-NUL chars not allowed within request variables - dropped variable 'info_hash' (attacker '10.0.0.78', file '/usr/local/captiveportal/index.php')

    Jan 31 17:35:49 lighttpd[18696]: (mod_fastcgi.c.2676) FastCGI-stderr: ALERT - ASCII-NUL chars not allowed within request variables - dropped variable 'checklic' (attacker '10.0.0.74', file '/usr/local/captiveportal/index.php')
    Jan 31 17:35:49 lighttpd[18696]: (mod_fastcgi.c.2676) FastCGI-stderr: ALERT - ASCII-NUL chars not allowed within request variables - dropped variable 'checklic' (attacker '10.0.0.74', file '/usr/local/captiveportal/index.php')


Log in to reply