I have to manually reset states after WAN down to allow Asterisk to re-register.



  • Hello,
        I am experiencing an issue with Asterisk not reconnecting unless I manually delete the states.

    Un-ticking this option does not provide a resolution…even though it should remove all active states.

    Happy to try anything and provide whatever debug info. is needed.  Thanks for looking !

    Summary:

    Everything works perfectly, until I pull out and plugin the phone line to the dsl modem…then Asterisk can no longer register with my provider.
    I did not have this issue prior to using pfsense.

    I am testing by removing the phone line from the dsl modem (which is in bridged mode connected to the wan port with pfsense doing PPPoE).

    Asterisk 1.8.20.1 (running as Elastix 2.4).
    pfsense 2.1-RELEASE (i386)  built on Wed Sep 11 18:16:22 EDT 2013 FreeBSD 8.3-RELEASE-p11

    I have set up a static rule using "Manual Outbound NAT rule generation (AON - Advanced Outbound NAT)"

    I also have port forwarded 10000-20000.

    This is what i see in the system log…

    Dec 11 13:10:58	apinger: alarm canceled: WAN_PPPOE(202.138.4.81) *** WAN_PPPOEdown ***
    Dec 11 13:12:15	apinger: ALARM: WAN_PPPOE(202.138.4.81) *** WAN_PPPOEdown ***
    Dec 11 13:17:17	apinger: SIGHUP received, reloading configuration.
    Dec 11 13:17:17	apinger: alarm canceled (config reload): WAN_PPPOE(202.138.4.81) *** WAN_PPPOEdown ***
    
    
    Dec 11 13:17:17	php: rc.newwanip: ROUTING: setting default route to 202.138.4.81
    Dec 11 13:17:17	php: rc.newwanip: DynDns: updatedns() starting
    ...
    Dec 11 13:17:32	php: rc.newwanip: pfSense package system has detected an ip change 211.27.74.200 -> 116.240.129.229 ... Restarting packages.
    Dec 11 13:17:32	check_reload_status: Starting packages
    Dec 11 13:17:32	check_reload_status: Reloading filter
    Dec 11 13:17:34	php: rc.start_packages: Restarting/Starting all packages.
    Dec 11 13:17:35	php: rc.filter_configure_sync: Not installing NAT reflection rules for a port range > 500
    Dec 11 13:17:37	php: rc.start_packages: The command '/usr/local/etc/rc.d/bandwidthd.sh stop' returned exit code '1', the output was 'No matching processes were found'
    Dec 11 13:17:40	bandwidthd: Monitoring subnet 192.168.0.0 with netmask 192.168.0.0
    Dec 11 13:17:42	bandwidthd: Monitoring subnet 192.168.0.0 with netmask 192.168.0.0
    Dec 11 13:17:42	bandwidthd: Opening em0
    Dec 11 13:17:42	bandwidthd: Opening em0
    Dec 11 13:17:42	bandwidthd: Opening em0
    Dec 11 13:17:42	bandwidthd: Opening em0
    Dec 11 13:17:42	bandwidthd: Packet Encoding: Ethernet
    Dec 11 13:17:42	bandwidthd: Packet Encoding: Ethernet
    Dec 11 13:17:42	bandwidthd: Packet Encoding: Ethernet
    Dec 11 13:17:42	bandwidthd: Packet Encoding: Ethernet
    Dec 11 13:17:44	nrpe[70969]: Caught SIGTERM - shutting down...
    Dec 11 13:17:44	nrpe[70969]: Cannot remove pidfile '/var/run/nrpe2.pid' - check your privileges.
    Dec 11 13:17:44	nrpe[70969]: Daemon shutdown
    Dec 11 13:17:44	nrpe[94420]: Starting up daemon
    Dec 11 13:17:44	nrpe[94420]: Listening for connections on port 5666
    Dec 11 13:17:44	nrpe[94420]: Allowing connections from: 127.0.0.1
    Dec 11 13:17:46	php: rc.start_packages: No pfBlocker action during boot process.
    Dec 11 13:17:46	php: rc.start_packages: No pfBlocker action during boot process.
    Dec 11 13:17:46	php: rc.start_packages: No pfBlocker action during boot process.
    Dec 11 13:17:46	php: rc.start_packages: No pfBlocker action during boot process.
    Dec 11 13:17:48	php: rc.start_packages: Reloading Squid for configuration sync
    Dec 11 13:17:48	check_reload_status: Reloading filter
    Dec 11 13:17:50	php: rc.start_packages: Reloading Squid for configuration sync
    Dec 11 13:17:50	php: rc.start_packages: Reloading Squid for configuration sync
    Dec 11 13:17:50	php: rc.start_packages: Not calling package sync code for dependency squid of squid because some include files are missing.
    Dec 11 13:17:50	php: rc.start_packages: Reloading Squid for configuration sync
    Dec 11 13:17:50	php: rc.start_packages: Reloading Squid for configuration sync
    Dec 11 13:17:50	php: rc.start_packages: Reloading Squid for configuration sync
    Dec 11 13:17:50	php: rc.start_packages: Reloading Squid for configuration sync
    Dec 11 13:17:51	php: rc.filter_configure_sync: Not installing NAT reflection rules for a port range > 500
    Dec 11 13:17:54	squid[99913]: Squid Parent: child process 272 exited with status 0
    Dec 11 13:17:55	php: rc.start_packages: The command '/usr/local/etc/rc.d/squid.sh stop' returned exit code '1', the output was ''
    Dec 11 13:17:57	squid[43512]: Squid Parent: child process 43730 started
    Dec 11 13:17:59	php: rc.start_packages: The command '/usr/local/etc/rc.d/darkstat.sh stop' returned exit code '1', the output was 'No matching processes were found'
    




    Is there anything else I should be doing?

    It all works fine, except for the re-registering…(which works immediately that I delete the states).

    As a temporary workaround, I have modified /usr/local/sbin/ppp-linkup as suggested in this post

    It calls the following script (/usr/local/sbin/voip-wan-wipe-states) to clear the states for the asterisk session once the Wan (PPPoE) is back up.

    #!/bin/sh
    sleep 30
    pfctl -k 192.168.0.5
    
    

    Surely this should not be needed as this is what unticking the box in the settings should do…no?


  • Netgate Administrator

    Hmm this should have been fixed:
    https://redmine.pfsense.org/issues/2887

    Do you have those revisions in rc.kill_states?

    Steve



  • Hi Thanks for the reply…I read it was fixed too so this is quite puzzling.

    Below is the code in /etc/rc.kill_states...
    Perhaps I need to put some logging code in there to see why it appears not to be removing the states.

    cat  /etc/rc.kill_states
    #!/usr/local/bin/php -f
    /

            rc.newwanip
            Copyright (C) 2013 Renato Botelho (garga@pfsense.org)
            part of pfSense (http://www.pfsense.com)

    Redistribution and use in source and binary forms, with or without
            modification, are permitted provided that the following conditions are m                                              et:

    1. Redistributions of source code must retain the above copyright notice                                              ,
            this list of conditions and the following disclaimer.

    2. Redistributions in binary form must reproduce the above copyright
            notice, this list of conditions and the following disclaimer in the
            documentation and/or other materials provided with the distribution.

    THIS SOFTWARE IS PROVIDED ``AS IS'' AND ANY EXPRESS OR IMPLIED WARRANTIE                                              S,
            INCLUDING, BUT NOT LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY
            AND FITNESS FOR A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL T                                              HE
            AUTHOR BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLAR                                              Y,
            OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
            SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
            INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
            CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
            ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF T                                              HE
            POSSIBILITY OF SUCH DAMAGE.
    */

    /* parse the configuration and include all functions used below */
    require_once("globals.inc");
    require_once("config.inc");
    require_once("interfaces.inc");
    require_once("util.inc");

    // Do not process while booting
    if($g['booting'])
            exit;

    /* Interface address to cleanup states */
    $interface = str_replace("\n", "", $argv[1]);

    /* IP address to cleanup states */
    $local_ip = str_replace("\n", "", $argv[2]);

    if (empty($interface) || !does_interface_exist($interface)) {
            log_error("rc.kill_states: Invalid interface '{$interface}'");
            exit;
    }

    if (!empty($local_ip)) {
            list($local_ip, $subnet_bits) = explode("/", $local_ip);

    if (empty($subnet_bits))
                    $subnet_bits = "32";

    if (!is_ipaddr($local_ip)) {
                    log_error("rc.kill_states: Invalid IP address '{$local_ip}'");
                    exit;
            }
    }

    if (!isset($config['system']['kill_states'])) {
            if (!empty($local_ip)) {
                    log_error("rc.kill_states: Removing states for IP {$local_ip}/{$                                              subnet_bits}");
                    $nat_states = exec_command("/sbin/pfctl -i {$interface} -ss | "                                                .
                            "/usr/bin/egrep '-> +{$local_ip}:[0-9]+ +->'");

    $cleared_states = array();
                    foreach(explode("\n", $nat_states) as $nat_state) {
                            if (preg_match_all('/([\d.]+):[\d]+[\s->]+/i', $nat_sta                                              te, $matches, PREG_SET_ORDER) != 3)
                                    continue;

    $src = $matches[0][1];
                            $dst = $matches[2][1];

    if (empty($src) || empty($dst) || in_array("{$src},{$dst                                              }", $cleared_states))
                                    continue;

    $cleared_states[] = "{$src},{$dst}";
                            mwexec("/sbin/pfctl -k {$src} -k {$dst}", true);
                    }

    mwexec("/sbin/pfctl -k 0.0.0.0/0 -k {$local_ip}/{$subnet_bits}",                                                true);
                    mwexec("/sbin/pfctl -k {$local_ip}/{$subnet_bits}", true);
                    mwexec("/sbin/pfctl -K {$local_ip}/{$subnet_bits}", true);
            }
            log_error("rc.kill_states: Removing states for interface {$interface}");
            mwexec("/sbin/pfctl -i {$interface} -Fs", true);



  • Just a 'me too' here, though I'm using a cablemodem rather than dsl, and a linksys PAP2T adapter rather than asterisk.  My symptoms are exactly the same: when my cable modem occasionally reboots itself, everything comes back up with the same wan IP.  But the VOIP adapter cannot register until I manually delete the two states illustrated above (single:no_traffic and no_traffic:single, on ports 5060).

    I do have the state-killing box un-checked, and I see no evidence in syslog that rc.kill_states has ever run.

    Reading through the commits in the bug, I see that rc.kill_states is only called from /usr/local/sbin/ppp-linkdown.  What about WAN links other than PPP?  How are the firewall states killed for those?  I guess that explains why it never gets called for me …


  • Netgate Administrator

    Good point. You are using DHCP on WAN I take it?
    The OP is using PPPoE though.  :-\

    Steve



  • @stephenw10:

    Good point. You are using DHCP on WAN I take it?

    Yes, DHCP on WAN, to Motorola Surfboard cable modem.  Hmm, what a coincidence, my cable modem re-booted itself last night a few hours after my last reply, so I didn't have to wait long.

    Rather than try to pick out what's useful, here is my whole syslog from the time WAN went down until now, hope it's not too big.  In this log:

    • 192.168.100.5, OPT1 on bge1_vlan2 is so I can browse to my cable modem on 192.168.100.1
    • /dev/bge1 is WAN, DHCP to cable modem, shown as 24.74.xx.yyy below
    • /dev/bge0 is LAN, static IP
    • 24.74.32.1 is WAN gateway
    
    Dec 14 19:40:49 pfsense sshd[76024]: Accepted keyboard-interactive/pam for root from 192.168.2.1 port 33826 ssh2
    Dec 15 02:10:30 pfsense lighttpd[34032]: (connections.c.305) SSL: 1 error:1407609C:SSL routines:SSL23_GET_CLIENT_HELLO:http request 
    Dec 15 02:20:30 pfsense check_reload_status: Linkup starting bge1
    Dec 15 02:20:30 pfsense kernel: bge1: link state changed to DOWN
    Dec 15 02:20:30 pfsense kernel: bge1_vlan2: link state changed to DOWN
    Dec 15 02:20:30 pfsense check_reload_status: Linkup starting bge1_vlan2
    Dec 15 02:20:32 pfsense php: rc.linkup: DEVD Ethernet detached event for wan
    Dec 15 02:20:32 pfsense php: rc.linkup: Hotplug event detected for OPT1(opt1) but ignoring since interface is configured with static IP (192.168.100.5 )
    Dec 15 02:20:34 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:35 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:35 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:36 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:36 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:36 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:36 pfsense php: rc.linkup: Clearing states to old gateway 24.74.32.1.
    Dec 15 02:20:37 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:38 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:39 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:40 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:41 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:42 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:43 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:43 pfsense check_reload_status: Linkup starting bge1
    Dec 15 02:20:43 pfsense kernel: bge1: link state changed to UP
    Dec 15 02:20:43 pfsense kernel: bge1_vlan2: link state changed to UP
    Dec 15 02:20:43 pfsense check_reload_status: Linkup starting bge1_vlan2
    Dec 15 02:20:44 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:45 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:46 pfsense php: rc.linkup: DEVD Ethernet attached event for wan
    Dec 15 02:20:46 pfsense php: rc.linkup: HOTPLUG: Configuring interface wan
    Dec 15 02:20:46 pfsense php: rc.linkup: The command '/sbin/ifconfig 'bge1' inet  delete' returned exit code '1', the output was 'ifconfig: ioctl (SIOCDIFADDR): Can't assign requested address' 
    Dec 15 02:20:46 pfsense php: rc.linkup: Hotplug event detected for OPT1(opt1) but ignoring since interface is configured with static IP (192.168.100.5 )
    Dec 15 02:20:46 pfsense check_reload_status: rc.newwanip starting bge1_vlan2
    Dec 15 02:20:46 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:47 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:48 pfsense kernel: bge1: link state changed to DOWN
    Dec 15 02:20:48 pfsense kernel: bge1_vlan2: link state changed to DOWN
    Dec 15 02:20:48 pfsense check_reload_status: Linkup starting bge1
    Dec 15 02:20:48 pfsense check_reload_status: Linkup starting bge1_vlan2
    Dec 15 02:20:48 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:48 pfsense php: rc.newwanip: rc.newwanip: Informational is starting bge1_vlan2.
    Dec 15 02:20:48 pfsense php: rc.newwanip: rc.newwanip: on (IP address: 192.168.100.5) (interface: opt1) (real interface: bge1_vlan2).
    Dec 15 02:20:48 pfsense check_reload_status: Reloading filter
    Dec 15 02:20:49 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:50 pfsense php: rc.linkup: DEVD Ethernet detached event for wan
    Dec 15 02:20:50 pfsense php: rc.linkup: The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf bge1 > /tmp/bge1_output 2> /tmp/bge1_error_output' returned exit code '15', the output was '' 
    Dec 15 02:20:50 pfsense php: rc.linkup: Accept router advertisements on interface bge1 
    Dec 15 02:20:50 pfsense check_reload_status: updating dyndns WAN_DHCP
    Dec 15 02:20:50 pfsense check_reload_status: Restarting ipsec tunnels
    Dec 15 02:20:50 pfsense check_reload_status: Restarting OpenVPN tunnels/interfaces
    Dec 15 02:20:50 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:50 pfsense php: rc.linkup: Hotplug event detected for OPT1(opt1) but ignoring since interface is configured with static IP (192.168.100.5 )
    Dec 15 02:20:50 pfsense check_reload_status: Linkup starting bge1
    Dec 15 02:20:50 pfsense kernel: bge1: link state changed to UP
    Dec 15 02:20:50 pfsense kernel: bge1_vlan2: link state changed to UP
    Dec 15 02:20:50 pfsense check_reload_status: Linkup starting bge1_vlan2
    Dec 15 02:20:51 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:20:51 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:20:51 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:20:51 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:20:51 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:20:51 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:20:51 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:20:51 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:20:53 pfsense php: rc.linkup: DEVD Ethernet attached event for wan
    Dec 15 02:20:53 pfsense php: rc.linkup: HOTPLUG: Configuring interface wan
    Dec 15 02:20:53 pfsense php: rc.linkup: Hotplug event detected for OPT1(opt1) but ignoring since interface is configured with static IP (192.168.100.5 )
    Dec 15 02:20:53 pfsense php: rc.linkup: The command '/sbin/ifconfig 'bge1' inet  delete' returned exit code '1', the output was 'ifconfig: ioctl (SIOCDIFADDR): Can't assign requested address' 
    Dec 15 02:20:53 pfsense check_reload_status: rc.newwanip starting bge1_vlan2
    Dec 15 02:20:54 pfsense check_reload_status: updating dyndns wan
    Dec 15 02:20:55 pfsense php: rc.newwanip: rc.newwanip: Informational is starting bge1_vlan2.
    Dec 15 02:20:55 pfsense php: rc.newwanip: rc.newwanip: on (IP address: 192.168.100.5) (interface: opt1) (real interface: bge1_vlan2).
    Dec 15 02:20:56 pfsense sshd[76024]: fatal: Write failed: Operation not permitted
    Dec 15 02:20:56 pfsense sshd[76024]: fatal: Write failed: Operation not permitted
    Dec 15 02:21:01 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:21:01 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:21:01 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:21:01 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:21:01 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:21:01 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:21:01 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:21:08 pfsense php: rc.newipsecdns: IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
    Dec 15 02:21:14 pfsense check_reload_status: rc.newwanip starting bge1
    Dec 15 02:21:14 pfsense php: rc.linkup: Accept router advertisements on interface bge1 
    Dec 15 02:21:14 pfsense php: rc.linkup: ROUTING: setting default route to 24.74.32.1
    Dec 15 02:21:17 pfsense php: rc.newwanip: rc.newwanip: Informational is starting bge1.
    Dec 15 02:21:17 pfsense php: rc.newwanip: rc.newwanip: on (IP address: 24.74.xx.yyy) (interface: wan) (real interface: bge1).
    Dec 15 02:21:17 pfsense php: rc.newwanip: ROUTING: setting default route to 24.74.32.1
    Dec 15 02:21:17 pfsense php: rc.newwanip: Removing static route for monitor 8.8.8.8 and adding a new route through 24.74.32.1
    Dec 15 02:21:17 pfsense check_reload_status: updating dyndns wan
    Dec 15 02:21:18 pfsense php: rc.newipsecdns: Forcefully reloading IPsec racoon daemon
    Dec 15 02:21:22 pfsense php: rc.newwanip: Forcefully reloading IPsec racoon daemon
    Dec 15 02:21:22 pfsense php: rc.newwanip: Resyncing OpenVPN instances for interface WAN.
    Dec 15 02:21:22 pfsense php: rc.newwanip: Creating rrd update script
    Dec 15 02:21:24 pfsense php: rc.newwanip: pfSense package system has detected an ip change 24.74.xx.yyy ->  24.74.xx.yyy ... Restarting packages.
    Dec 15 02:21:24 pfsense check_reload_status: Starting packages
    Dec 15 02:21:24 pfsense check_reload_status: Reloading filter
    Dec 15 02:21:25 pfsense check_reload_status: updating dyndns WAN_DHCP
    Dec 15 02:21:25 pfsense check_reload_status: Restarting ipsec tunnels
    Dec 15 02:21:25 pfsense check_reload_status: Restarting OpenVPN tunnels/interfaces
    Dec 15 02:21:26 pfsense php: rc.start_packages: Restarting/Starting all packages.
    Dec 15 02:21:31 pfsense lighttpd[34032]: (connections.c.1721) SSL (error): 5 -1 1 Operation not permitted 
    Dec 15 02:21:43 pfsense php: rc.newipsecdns: IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
    Dec 15 02:21:53 pfsense php: rc.newipsecdns: Forcefully reloading IPsec racoon daemon
    Dec 15 02:22:30 pfsense check_reload_status: Linkup starting bge1
    Dec 15 02:22:30 pfsense kernel: bge1: link state changed to DOWN
    Dec 15 02:22:30 pfsense kernel: bge1_vlan2: link state changed to DOWN
    Dec 15 02:22:30 pfsense check_reload_status: Linkup starting bge1_vlan2
    Dec 15 02:22:33 pfsense php: rc.linkup: DEVD Ethernet detached event for wan
    Dec 15 02:22:33 pfsense php: rc.linkup: Hotplug event detected for OPT1(opt1) but ignoring since interface is configured with static IP (192.168.100.5 )
    Dec 15 02:22:34 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:22:35 pfsense kernel: arpresolve: can't allocate llinfo for 24.74.32.1
    Dec 15 02:22:37 pfsense php: rc.linkup: Clearing states to old gateway 24.74.32.1.
    Dec 15 02:22:43 pfsense check_reload_status: Linkup starting bge1
    Dec 15 02:22:43 pfsense kernel: bge1: link state changed to UP
    Dec 15 02:22:43 pfsense kernel: bge1_vlan2: link state changed to UP
    Dec 15 02:22:43 pfsense check_reload_status: Linkup starting bge1_vlan2
    Dec 15 02:22:46 pfsense php: rc.linkup: DEVD Ethernet attached event for wan
    Dec 15 02:22:46 pfsense php: rc.linkup: HOTPLUG: Configuring interface wan
    Dec 15 02:22:46 pfsense php: rc.linkup: Hotplug event detected for OPT1(opt1) but ignoring since interface is configured with static IP (192.168.100.5 )
    Dec 15 02:22:46 pfsense check_reload_status: rc.newwanip starting bge1_vlan2
    Dec 15 02:22:46 pfsense php: rc.linkup: The command '/sbin/ifconfig 'bge1' inet  delete' returned exit code '1', the output was 'ifconfig: ioctl (SIOCDIFADDR): Can't assign requested address' 
    Dec 15 02:22:47 pfsense check_reload_status: Linkup starting bge1
    Dec 15 02:22:47 pfsense kernel: bge1: link state changed to DOWN
    Dec 15 02:22:47 pfsense kernel: bge1_vlan2: link state changed to DOWN
    Dec 15 02:22:47 pfsense check_reload_status: Linkup starting bge1_vlan2
    Dec 15 02:22:48 pfsense php: rc.newwanip: rc.newwanip: Informational is starting bge1_vlan2.
    Dec 15 02:22:48 pfsense php: rc.newwanip: rc.newwanip: on (IP address: 192.168.100.5) (interface: opt1) (real interface: bge1_vlan2).
    Dec 15 02:22:48 pfsense check_reload_status: Reloading filter
    Dec 15 02:22:49 pfsense check_reload_status: Linkup starting bge1
    Dec 15 02:22:49 pfsense kernel: bge1: link state changed to UP
    Dec 15 02:22:49 pfsense kernel: bge1_vlan2: link state changed to UP
    Dec 15 02:22:49 pfsense check_reload_status: Linkup starting bge1_vlan2
    Dec 15 02:22:49 pfsense php: rc.linkup: Hotplug event detected for OPT1(opt1) but ignoring since interface is configured with static IP (192.168.100.5 )
    Dec 15 02:22:49 pfsense php: rc.linkup: DEVD Ethernet detached event for wan
    Dec 15 02:22:49 pfsense php: rc.linkup: The command '/sbin/dhclient -c /var/etc/dhclient_wan.conf bge1 > /tmp/bge1_output 2> /tmp/bge1_error_output' returned exit code '15', the output was '' 
    Dec 15 02:22:49 pfsense php: rc.linkup: Accept router advertisements on interface bge1 
    Dec 15 02:22:50 pfsense check_reload_status: updating dyndns WAN_DHCP
    Dec 15 02:22:50 pfsense check_reload_status: Restarting ipsec tunnels
    Dec 15 02:22:50 pfsense check_reload_status: Restarting OpenVPN tunnels/interfaces
    Dec 15 02:22:51 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:22:51 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:22:51 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:22:51 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:22:51 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:22:51 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:22:51 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:22:52 pfsense php: rc.linkup: Hotplug event detected for OPT1(opt1) but ignoring since interface is configured with static IP (192.168.100.5 )
    Dec 15 02:22:52 pfsense check_reload_status: rc.newwanip starting bge1_vlan2
    Dec 15 02:22:52 pfsense php: rc.linkup: DEVD Ethernet attached event for wan
    Dec 15 02:22:52 pfsense php: rc.linkup: HOTPLUG: Configuring interface wan
    Dec 15 02:22:52 pfsense php: rc.linkup: The command '/sbin/ifconfig 'bge1' inet  delete' returned exit code '1', the output was 'ifconfig: ioctl (SIOCDIFADDR): Can't assign requested address' 
    Dec 15 02:22:53 pfsense check_reload_status: updating dyndns wan
    Dec 15 02:22:54 pfsense php: rc.newwanip: rc.newwanip: Informational is starting bge1_vlan2.
    Dec 15 02:22:54 pfsense php: rc.newwanip: rc.newwanip: on (IP address: 192.168.100.5) (interface: opt1) (real interface: bge1_vlan2).
    Dec 15 02:23:00 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:23:00 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:23:00 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:23:00 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:23:00 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:23:00 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:23:00 pfsense php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
    Dec 15 02:23:08 pfsense php: rc.newipsecdns: IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
    Dec 15 02:23:12 pfsense check_reload_status: rc.newwanip starting bge1
    Dec 15 02:23:12 pfsense php: rc.linkup: Accept router advertisements on interface bge1 
    Dec 15 02:23:12 pfsense php: rc.linkup: ROUTING: setting default route to 24.74.32.1
    Dec 15 02:23:15 pfsense php: rc.newwanip: rc.newwanip: Informational is starting bge1.
    Dec 15 02:23:15 pfsense php: rc.newwanip: rc.newwanip: on (IP address: 24.74.xx.yyy) (interface: wan) (real interface: bge1).
    Dec 15 02:23:15 pfsense php: rc.newwanip: ROUTING: setting default route to 24.74.32.1
    Dec 15 02:23:15 pfsense php: rc.newwanip: Removing static route for monitor 8.8.8.8 and adding a new route through 24.74.32.1
    Dec 15 02:23:16 pfsense check_reload_status: updating dyndns wan
    Dec 15 02:23:18 pfsense php: rc.newipsecdns: Forcefully reloading IPsec racoon daemon
    Dec 15 02:23:20 pfsense php: rc.newwanip: Forcefully reloading IPsec racoon daemon
    Dec 15 02:23:20 pfsense php: rc.newwanip: Resyncing OpenVPN instances for interface WAN.
    Dec 15 02:23:20 pfsense php: rc.newwanip: Creating rrd update script
    Dec 15 02:23:22 pfsense php: rc.newwanip: pfSense package system has detected an ip change 24.74.xx.yyy ->  24.74.xx.yyy ... Restarting packages.
    Dec 15 02:23:22 pfsense check_reload_status: Starting packages
    Dec 15 02:23:22 pfsense check_reload_status: Reloading filter
    Dec 15 02:23:23 pfsense check_reload_status: updating dyndns WAN_DHCP
    Dec 15 02:23:23 pfsense check_reload_status: Restarting ipsec tunnels
    Dec 15 02:23:23 pfsense check_reload_status: Restarting OpenVPN tunnels/interfaces
    Dec 15 02:23:25 pfsense php: rc.start_packages: Restarting/Starting all packages.
    Dec 15 02:23:41 pfsense php: rc.newipsecdns: IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
    Dec 15 02:23:51 pfsense php: rc.newipsecdns: Forcefully reloading IPsec racoon daemon
    Dec 15 04:31:14 pfsense lighttpd[34032]: (connections.c.305) SSL: 1 error:1407609C:SSL routines:SSL23_GET_CLIENT_HELLO:http request 
    Dec 15 08:23:36 pfsense sshd[32210]: Accepted keyboard-interactive/pam for root from 192.168.2.1 port 59083 ssh2
    
    

    And here is my state table, filtered for 192.168.2.245 (my linksys VOIP adapter).  Attached (how to post images in-line?)



  • Netgate Administrator

    I've not dealt with this at all. You could try running rc.kill_states manually, looks like it needs some arguments passed to it, maybe:

    /etc/rc.kill_states wan your_wan_IP_address
    

    Doesn't help long term though.

    Is this a known issue? Seems like it would be.

    Steve

    Edit: More discussion here: https://redmine.pfsense.org/issues/1629
    Looks like a real fix will go in for 2.2.



  • @stephenw10:

    I've not dealt with this at all. You could try running rc.kill_states manually, looks like it needs some arguments passed to it, maybe:

    /etc/rc.kill_states wan your_wan_IP_address
    

    Doesn't help long term though.

    Running it manually doesn't work.  It runs, but doesn't clear the states:

    ./rc.kill_states bge1 24.74.xx.yyy
    puts this in syslog:
    Dec 15 09:44:25 pfsense php: rc.kill_states: rc.kill_states: Removing states for IP 24.74.xx.yyy/32
    Dec 15 09:44:25 pfsense php: rc.kill_states: rc.kill_states: Removing states for interface bge1
    
    

    But old states are still there, and still no adapter registration.  States screenshot attached after running rc.kill_states manually.

    Another strange problem is that ntpd is restarted, but takes 100% CPU until I go to 'Services –> ntp' and hit 'save'.  Screenshot attached, but that should be another thread unless it's related.

    Is this a known issue? Seems like it would be.

    Steve

    Edit: More discussion here: https://redmine.pfsense.org/issues/1629
    Looks like a real fix will go in for 2.2.

    Well it's at least known to me and davros123  :)






  • @stephenw10:

    Edit: More discussion here: https://redmine.pfsense.org/issues/1629
    Looks like a real fix will go in for 2.2.

    Hmm:

    #3181 is a band-aid for 2.1, this will need to wait 2.2
    

    Would be nice if we could get a working band-aid, as it sounds like 2.2 is still a long way off.


  • Netgate Administrator

    You would have to feed it your old IP. Presumably this gets run when the gateway is detected as down rather than when when it is up again.

    Steve



  • @stephenw10:

    You would have to feed it your old IP. Presumably this gets run when the gateway is detected as down rather than when when it is up again.

    WAN IP doesn't change with my cable modem reset.  Well, generally it doesn't; I think it did once a few months ago, first time in 3-4 years.



  • So, any thoughts on what I should be looking at to debug this issue?



  • @davros123:

    So, any thoughts on what I should be looking at to debug this issue?

    Seems the issues are well-understood, but the 'band-aid' fix put in for 2.1 was evidently not effective in cases like ours.  So debugging at this point would be to see why it's not effective in our cases.  Read through the history and associated revisions here:
    https://redmine.pfsense.org/issues/1629 and
    https://redmine.pfsense.org/issues/3181

    There were some commits that reverted fixes that were deemed too excessive.  At this point, I'll take excessive, big-hammer type fixes, but I haven't had time to go back and try anything.



  • Thanks. When I get some time i'll put some debug code in there and see if I can work out why it is not clearing the states.

    for now, my added kill code in ppp-linkup is working.



  • OK, I have re-applied this commit  to my system.  It is the 'big hammer' approach, and I'm OK with that.  If you are using multi-WAN, you probably don't want this.

    That patch was later backed out (with this) and a few minutes later further modified (with this) with the comment "Ticket #3181 do the state flushing only on down gateway detection rather than any time".

    I believe something in the last patch broke the state killing on my system.  I'll follow up here next time my cable modem drops out.



  • @charliem:

    OK, I have re-applied this commit  to my system.  It is the 'big hammer' approach, and I'm OK with that.  If you are using multi-WAN, you probably don't want this.

    I can confirm that re-applying the patch above fixed the reset states issue for me.  My cable modem reset itself yesterday, and after coming back up, my VOIP adapter was able to register no problem.

    Would be great if a fix for this could go into 2.1.1



  • ermal rverted that particular "fix" and made a more refined version: https://github.com/pfsense/pfsense/commit/19d723d2af5e8392d372720ef97b5b83336ec9e1 So it would be useful for people to confirm that the refined version works for their various use cases.
    Or go for broke and use the latest filter.inc from the 2.1 branch - https://github.com/pfsense/pfsense/blob/RELENG_2_1/etc/inc/filter.inc



  • @phil.davis:

    ermal rverted that particular "fix" and made a more refined version: https://github.com/pfsense/pfsense/commit/19d723d2af5e8392d372720ef97b5b83336ec9e1 So it would be useful for people to confirm that the refined version works for their various use cases.

    Yep, I noted that a few messages up.  That 'more refined' version patch (5-Sep) was in 2.1 Release when built (11-Sep), and did not work for me or the OP here as noted.

    Or go for broke and use the latest filter.inc from the 2.1 branch - https://github.com/pfsense/pfsense/blob/RELENG_2_1/etc/inc/filter.inc

    I thought of that, but did not (yet) try it because:

    • The commits since then did not seem to be in related areas,
    • I thought it would be good to confirm which patch broke my use case

    I can try it if it would be helpful though.



  • I guess the key here is the "on gateway failure" part. It uses the monitor functionality to test the link, and it never seems to fail, because it reconnects fast and in the next test it's up again/yet. So it never triggers. Note that i'm only talking about that checkbox (i also have it unchecked and it does not work for this particular problem).

    That said, there is code in place that detects the wan ip change, but it does not seem to be the one that is calling rc.kill_states. There seem to be some confusion there. In those other threads (cited above) people seemed to have understood the problem well and were right on track to solving it, a patch was already working (that later was reversed because caused some other bugs) but in the last minute, in another thread, Cris modified the code to only trigger when gateway fails, said 'works' and marked as done. In the previous thread it was said that it was a bandaid and the real fix is for 2.2. Well, the bandaid does not work for this case.

    The only really working solution so far is the one proposed in this thread (using ppp's ipup script), but that is clumsy for the average user and might get overwritten in the next update. There is about 4 or 5 other threads about this and all of them conclude with this being fixed with some commit before 2.1, but it's still there on 2.1.

    I understand that a real/good solution could only be possible on 2.2, but we could get a bandaid that really works for 2.1.1 at least. Even if the solution is the big-hammer one of killing every state and giving the user a checkbox to enable it (not to confuse with the other checkbox that was commented above). Or the one in ipup that works too.

    Maybe a section on the gui for the user to list all ips of voip devices that should have states tottally assassinated on wan ip change, and use this info to construct the calls to pfctl -k that should go in the ipup script. This way it gests more manageable, easy and upgrades-proof. But this only solves the problem for PPPoE, not for DHCP. And it also does not solve the case where the IP does not change, only the interface goes down/up and get the same IP again (which leaves some problems behind and should be treated like if there was an IP change).



  • Hello,

    I realize this topic is a little old but I am having the same issue running 2.1. Are there any updates to resolve this issue? I noticed Bug #1629 may be related to this.



  • Same problem here (pfSense 2.1.4)

    WAN DHCP, static IP. My pbx does not register the trunks until I reset the state table, even with the "State Killing on Gateway Failure" option is de-selected.

    I'm not able to do replicate the problem, so after any change I have to wait (days) to see if something different is happening… :(



  • It's clear to me that this is not a high priority to be fixed with the 2.1.x series.  As a work-around for 2.1.x, look at my post here:
    https://forum.pfsense.org/index.php?topic=70418.msg387457#msg387457 and re-apply the patch that's in the link.

    Upgrading to 2.2 alpha has solved the problem for me, so you could consider that option as well.



  • @charliem:

    It's clear to me that this is not a high priority to be fixed with the 2.1.x series.  As a work-around for 2.1.x, look at my post here:
    https://forum.pfsense.org/index.php?topic=70418.msg387457#msg387457 and re-apply the patch that's in the link.

    Upgrading to 2.2 alpha has solved the problem for me, so you could consider that option as well.

    On 2.1.4 the commit that you suggest is not working.
    I applied the commit 19d723d2af5e8392d372720ef97b5b83336ec9e1 and it changed the filter.inc.

    I will update you on my next gateway down event :)



  • It is working like a charm =)



  • Still the same Problem on 2.3.3 for me.

    I have to do the following to fix it for me (found it some years ago on the pfsense forum):

    cd /usr/local/sbin
    vi voip-wan-wipe

    #!/bin/sh
    sleep 30
    pfctl -F state 
    

    chmod 755 voip-wan-wipe

    vi ppp-linkup and add before exit 0:

    /usr/local/sbin/voip-wan-wipe &
    

    Works for me like a charm.

    But my question is: Is there any better way to do it in the actual release of pfsense?



  • I think I'm having the same issue with a flaky DSL modem – but registering a SIP trunk with Grandstream PBX (which is an Asterisk flavor).

    I'm not sure that I understood the previous (last) reply: write the script and then call it as the last line in ppp-reconnect?  Does that work for a DHCP WAN connection too?  It's confusing to me that this is the only location (out of 16) that has this problem.

    Thanks!


Log in to reply