Nasty pppoe reconnection bug returns in 2.2 RC
-
im on the below snap, nanobsd, alix
2.2-RC (i386) built on Sun Dec 14 23:20:40 CST 2014 FreeBSD 10.1-RELEASE-p1
ill get back with the logs shortly
-
here is the log, kindly delete once u have looked at it
Removed
what i remember is the patch u applied in the below commit had fixed the issue last time
https://github.com/pfsense/pfsense-tools/commit/4d298135387ef551ccc6eff62a1705059956c64e -
Can you try this patch please and let me know if it fixes the issue.
diff --git a/etc/rc.newwanip b/etc/rc.newwanip index 56c2453..63da663 100755 --- a/etc/rc.newwanip +++ b/etc/rc.newwanip @@ -237,9 +237,9 @@ if (!is_ipaddr($oldip) || $curwanip != $oldip || !is_ipaddrv4($config['interface services_snmpd_configure(); restart_packages(); -} else { - /* signal filter reload */ - filter_configure(); } +/* signal filter reload */ +filter_configure(); + ?>
-
tried it, still same, i think its something to do with the via chipset drivers, is there any way to bring it down and up or something like that which can make it work after link up because the last time there was a driver patch or something applied and then it was flawless
system log
Dec 17 16:11:41 kernel: vr1: link state changed to DOWN Dec 17 16:12:34 check_reload_status: updating dyndns WAN Dec 17 16:12:34 check_reload_status: Restarting ipsec tunnels Dec 17 16:12:34 check_reload_status: Restarting OpenVPN tunnels/interfaces Dec 17 16:12:34 check_reload_status: Reloading filter Dec 17 16:12:37 php-fpm[33561]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN. Dec 17 16:12:37 php-fpm[33561]: /rc.openvpn: OpenVPN: Resync client1 ExpressVPN Dec 17 16:12:38 php-fpm[33102]: /rc.dyndns.update: phpDynDNS (firewall): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Dec 17 16:12:38 kernel: ovpnc1: link state changed to DOWN Dec 17 16:12:38 check_reload_status: Reloading filter Dec 17 16:12:45 php: rc.kill_states: rc.kill_states: Removing states for IP 86.99.127.170/32 Dec 17 16:12:45 check_reload_status: Rewriting resolv.conf Dec 17 16:12:46 php-fpm[33265]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:46 php-fpm[33265]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:47 php-fpm[33265]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:47 php-fpm[33265]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:47 php-fpm[33265]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:47 php-fpm[33265]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:47 php-fpm[33265]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:47 php-fpm[33265]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:47 php-fpm[33265]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:53 php-fpm[33561]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:53 php-fpm[33561]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:53 php-fpm[33561]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:53 php-fpm[33561]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:53 php-fpm[33561]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:53 php-fpm[33561]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:53 php-fpm[33561]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:53 php-fpm[33561]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:53 php-fpm[33561]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 17 16:12:56 check_reload_status: Linkup starting vr1 Dec 17 16:12:56 kernel: vr1: link state changed to UP Dec 17 16:13:29 syslogd: exiting on signal 15 Dec 17 16:13:29 syslogd: kernel boot file is /boot/kernel/kernel
ppp log is same
-
Ok can you apply this and let me know if you see the new message on system log?
diff --git a/etc/rc.linkup b/etc/rc.linkup index 59e2089..b6f06dd 100755 --- a/etc/rc.linkup +++ b/etc/rc.linkup @@ -142,8 +143,10 @@ if (!empty($realiface)) { /* The loop here is because ppp types can have real and assigned interfaces as members */ $tmpiface = get_real_interface($parent_if); $tmpiface = convert_real_interface_to_friendly_interface_name($tmpiface); - if (!empty($tmpiface)) + if (!empty($tmpiface)) { + log_error("Reconfiguring $realiface, $parent_if, $tmpiface"); interface_configure($tmpiface, true, true); + } } } }
-
do i use with the first patch or shall i revert the first patch and then apply the second one?
-
It does not matter.You can apply both or either
-
i applied both and then tried but i dont seem to get that message in system log and issue is as it is
Dec 18 08:57:45 kernel: vr1: link state changed to DOWN Dec 18 08:58:49 php: rc.kill_states: rc.kill_states: Removing states for IP 2.51.127.81/32 Dec 18 08:59:01 check_reload_status: Linkup starting vr1 Dec 18 08:59:01 kernel: vr1: link state changed to UP Dec 18 08:59:41 kernel: ovpnc1: link state changed to DOWN Dec 18 08:59:41 check_reload_status: Reloading filter Dec 18 08:59:48 php-fpm[5482]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 08:59:48 php-fpm[5482]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 08:59:48 php-fpm[5482]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 08:59:48 php-fpm[5482]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 08:59:48 php-fpm[5482]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 08:59:48 php-fpm[5482]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 08:59:48 php-fpm[5482]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 08:59:48 php-fpm[5482]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 08:59:49 php-fpm[5482]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 09:00:11 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 09:00:11 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 09:00:11 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 09:00:11 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 09:00:11 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 09:00:11 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 09:00:12 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 09:00:12 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 18 09:00:12 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Dec 18 08:58:18 ppp: [wan_link0] LCP: no reply to 2 echo request(s) Dec 18 08:58:38 ppp: [wan_link0] LCP: no reply to 4 echo request(s) Dec 18 08:58:48 ppp: [wan_link0] LCP: no reply to 5 echo request(s) Dec 18 08:58:48 ppp: [wan_link0] LCP: peer not responding to echo requests Dec 18 08:58:48 ppp: [wan_link0] LCP: state change Opened --> Stopping Dec 18 08:58:48 ppp: [wan_link0] Link: Leave bundle "wan" Dec 18 08:58:48 ppp: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps Dec 18 08:58:48 ppp: [wan] IPCP: Close event Dec 18 08:58:48 ppp: [wan] IPCP: state change Opened --> Closing Dec 18 08:58:48 ppp: [wan] IPCP: SendTerminateReq #4 Dec 18 08:58:48 ppp: [wan] IPCP: LayerDown Dec 18 08:58:50 ppp: [wan] IFACE: Delete route 0.0.0.0/0 2.48.4.1 failed: No such process Dec 18 08:58:50 ppp: [wan] IFACE: Down event Dec 18 08:58:50 ppp: [wan] IFACE: Rename interface pppoe0 to pppoe0 Dec 18 08:58:50 ppp: [wan] IPV6CP: Close event Dec 18 08:58:50 ppp: [wan] IPV6CP: state change Stopped --> Closed Dec 18 08:58:50 ppp: [wan] IPCP: Down event Dec 18 08:58:50 ppp: [wan] IPCP: LayerFinish Dec 18 08:58:50 ppp: [wan] Bundle: No NCPs left. Closing links... Dec 18 08:58:50 ppp: [wan] IPCP: state change Closing --> Initial Dec 18 08:58:50 ppp: [wan] IPV6CP: Down event Dec 18 08:58:50 ppp: [wan] IPV6CP: state change Closed --> Initial Dec 18 08:58:50 ppp: [wan_link0] LCP: SendTerminateReq #3 Dec 18 08:58:50 ppp: [wan_link0] LCP: LayerDown Dec 18 08:58:53 ppp: [wan_link0] LCP: SendTerminateReq #4 Dec 18 08:58:55 ppp: [wan_link0] LCP: state change Stopping --> Stopped Dec 18 08:58:55 ppp: [wan_link0] LCP: LayerFinish Dec 18 08:58:55 ppp: [wan_link0] PPPoE: connection closed Dec 18 08:58:55 ppp: [wan_link0] Link: DOWN event Dec 18 08:58:55 ppp: [wan_link0] LCP: Down event Dec 18 08:58:55 ppp: [wan_link0] LCP: state change Stopped --> Starting Dec 18 08:58:55 ppp: [wan_link0] LCP: LayerStart Dec 18 08:58:55 ppp: [wan_link0] Link: reconnection attempt 1 in 3 seconds Dec 18 08:58:58 ppp: [wan_link0] Link: reconnection attempt 1 Dec 18 08:58:58 ppp: [wan_link0] PPPoE: Connecting to ''
-
Can you show me from config.xml the interface section where pppoe is configured.
Also from ppp section related to this interface? -
<interfaces><wan><if>pppoe0</if> <bandwidth>100</bandwidth> <bandwidthtype>Mb</bandwidthtype> <spoofmac><disableftpproxy><enable><blockpriv><blockbogons><mtu>1492</mtu> <ipaddr>pppoe</ipaddr></blockbogons></blockpriv></enable></disableftpproxy></spoofmac></wan> <lan><if>vr0</if> <bandwidth>100</bandwidth> <bandwidthtype>Mb</bandwidthtype> <bridge><disableftpproxy><enable><spoofmac><ipaddr>192.168.0.1</ipaddr> <subnet>24</subnet></spoofmac></enable></disableftpproxy></bridge></lan> <opt2><if>ovpnc1</if> <spoofmac><enable></enable></spoofmac></opt2></interfaces>
<ppps><ppp><ptpid>0</ptpid> <type>pppoe</type> <if>pppoe0</if> <ports>vr1</ports> <username>username</username> <password>password</password> <ondemand><bandwidth><mtu><mru><mrru><provider><pppoe-reset-type>custom</pppoe-reset-type></provider></mrru></mru></mtu></bandwidth></ondemand></ppp></ppps>
-
I just pushed a fix beacause the code in rc.linkup was wrong.
The commit will apear or on github for you to test.
-
could u kindly give me the link so i can test?
-
ok dont bother, found it and applied and seems to work but will test once more tomorrow after a reboot and all possible scenarios and then give u final confirmation.
bytheway i found one bug, when pppoe reconnects, the serial console shows this which actually it shouldnt (check the last 2 lines)
FreeBSD/i386 (firewall) (ttyu0) *** Welcome to pfSense 2.2-RC-nanobsd (i386) on firewall *** WAN (wan) -> pppoe0 -> v4/PPPoE: x.x.x.x/32 LAN (lan) -> vr0 -> v4: 192.168.0.1/24 VPN (opt2) -> ovpnc1 -> v4: 10.10.0.222/32 0) Logout (SSH only) 9) pfTop 1) Assign Interfaces 10) Filter Logs 2) Set interface(s) IP address 11) Restart webConfigurator 3) Reset webConfigurator password 12) pfSense Developer Shell 4) Reset to factory defaults 13) Upgrade from console 5) Reboot system 14) Disable Secure Shell (sshd) 6) Halt system 15) Restore recent configuration 7) Ping host 16) Restart PHP-FPM 8) Shell Enter an option: Dec 18 18:45:13 php-fpm[52868]: /rc.newwanip: Removing static r oute for monitor y.y.y.y and adding a new route through z.z.z.z
-
The error log is during bootup or after?
-
It happens after, once the wan is disconnected and then it auto reconnects
-
Would one of you mind posting a link to the fixed code and a brief description of how to apply it? I am seeing the same problem with PPPoE on my DSL connection under pfSense 2.2 RC.
-
Would one of you mind posting a link to the fixed code and a brief description of how to apply it? I am seeing the same problem with PPPoE on my DSL connection under pfSense 2.2 RC.
OK, I found the commit in question at https://github.com/pfsense/pfsense/blob/ab0e40807d3a38972b04f75f8c9429bfb93f7a5d/etc/rc.linkup and manually edited it into the /etc/rc.linkup file using ee. I'm happy to say it did the trick.
-
well for me it worked once only and the next 5 times i tried it never worked
Dec 20 09:28:35 kernel: vr1: link state changed to DOWN Dec 20 09:29:41 php: rc.kill_states: rc.kill_states: Removing states for IP 92.99.177.145/32 Dec 20 09:29:41 check_reload_status: Rewriting resolv.conf Dec 20 09:29:46 kernel: ovpnc1: link state changed to DOWN Dec 20 09:29:46 check_reload_status: Reloading filter Dec 20 09:29:47 check_reload_status: updating dyndns WAN Dec 20 09:29:47 check_reload_status: Restarting ipsec tunnels Dec 20 09:29:47 check_reload_status: Restarting OpenVPN tunnels/interfaces Dec 20 09:29:47 check_reload_status: Reloading filter Dec 20 09:29:50 kernel: vr1: link state changed to UP Dec 20 09:29:50 check_reload_status: Linkup starting vr1 Dec 20 09:29:51 php-fpm[32866]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN. Dec 20 09:29:51 php-fpm[32866]: /rc.openvpn: OpenVPN: Resync client1 ExpressVPN Dec 20 09:29:51 check_reload_status: Reloading filter Dec 20 09:29:57 php-fpm[23733]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:29:57 php-fpm[23733]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:29:57 php-fpm[23733]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:29:57 php-fpm[23733]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:29:57 php-fpm[23733]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:29:57 php-fpm[23733]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:29:58 php-fpm[23733]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:29:58 php-fpm[23733]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:29:58 php-fpm[23733]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:05 php-fpm[32866]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:05 php-fpm[32866]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:05 php-fpm[32866]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:05 php-fpm[32866]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:05 php-fpm[32866]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:05 php-fpm[32866]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:05 php-fpm[32866]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:05 php-fpm[32866]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:05 php-fpm[32866]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:11 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:11 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:11 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:11 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:11 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:11 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:11 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:11 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:11 php: rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan). Dec 20 09:30:18 login: login on ttyu0 as root Dec 20 09:30:18 sshlockout[47575]: sshlockout/webConfigurator v3.0 starting up