PPPoE reconenction fix - mpd fix ($100)

eri-- · Feb 21, 2014, 11:52 AM

Ok coming back to this after some time.

I think i have solved the issue here and tomorrow snapshots should have a fix.
Can you test and let me know?

xbipin · Feb 21, 2014, 12:19 PM

ok ill try it out and revert back, can u post the link to the commit?

eri-- · Feb 21, 2014, 2:12 PM

https://github.com/pfsense/pfsense-tools/commit/4d298135387ef551ccc6eff62a1705059956c64e

https://github.com/pfsense/pfsense/commit/9510780ffa41bf1b19989b418e9a356702ba5576

xbipin · Feb 22, 2014, 12:51 PM

brilliant, almost after 2.5 years its solved now, plz send me ur paypal id for payment in PM

xbipin · Dec 15, 2014, 5:05 AM

the bug has appeared in 2.2 RC again and pppoe wont reconenct at all untill u reboot it, log is the same, just endless loops of connection attempts

eri-- · Jan 12, 2015, 9:37 PM

This should work as before or better in 2.2-RC++

xbipin · Jan 13, 2015, 5:17 AM

@ermal:

This should work as before or better in 2.2-RC++

well after the last changes u made the situation is same for me, if i unplug or modem goes down and up, then it wont connect at all in hours also, only way to make it connect is reboot.

xbipin · Jan 13, 2015, 6:45 AM

here r the logs with the latest snap

Jan 13 10:20:24 	ppp: [wan_link0] LCP: no reply to 2 echo request(s)
Jan 13 10:20:34 	ppp: [wan_link0] LCP: no reply to 3 echo request(s)
Jan 13 10:20:44 	ppp: [wan_link0] LCP: no reply to 4 echo request(s)
Jan 13 10:20:54 	ppp: [wan_link0] LCP: no reply to 5 echo request(s)
Jan 13 10:20:54 	ppp: [wan_link0] LCP: peer not responding to echo requests
Jan 13 10:20:54 	ppp: [wan_link0] LCP: state change Opened --> Stopping
Jan 13 10:20:54 	ppp: [wan_link0] Link: Leave bundle "wan"
Jan 13 10:20:54 	ppp: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Jan 13 10:20:54 	ppp: [wan] IPCP: Close event
Jan 13 10:20:54 	ppp: [wan] IPCP: state change Opened --> Closing
Jan 13 10:20:54 	ppp: [wan] IPCP: SendTerminateReq #4
Jan 13 10:20:54 	ppp: [wan] IPCP: LayerDown
Jan 13 10:20:55 	ppp: [wan] IFACE: Delete route 0.0.0.0/0 2.48.4.1 failed: No such process
Jan 13 10:20:55 	ppp: [wan] IFACE: Down event
Jan 13 10:20:55 	ppp: [wan] IFACE: Rename interface pppoe0 to pppoe0
Jan 13 10:20:55 	ppp: [wan] IPV6CP: Close event
Jan 13 10:20:55 	ppp: [wan] IPV6CP: state change Stopped --> Closed
Jan 13 10:20:55 	ppp: [wan] IPCP: Down event
Jan 13 10:20:55 	ppp: [wan] IPCP: LayerFinish
Jan 13 10:20:55 	ppp: [wan] Bundle: No NCPs left. Closing links...
Jan 13 10:20:55 	ppp: [wan] IPCP: state change Closing --> Initial
Jan 13 10:20:55 	ppp: [wan] IPV6CP: Down event
Jan 13 10:20:55 	ppp: [wan] IPV6CP: state change Closed --> Initial
Jan 13 10:20:55 	ppp: [wan_link0] LCP: SendTerminateReq #3
Jan 13 10:20:55 	ppp: [wan_link0] LCP: LayerDown
Jan 13 10:21:00 	ppp: [wan_link0] LCP: SendTerminateReq #4
Jan 13 10:21:02 	ppp: [wan_link0] LCP: state change Stopping --> Stopped
Jan 13 10:21:02 	ppp: [wan_link0] LCP: LayerFinish
Jan 13 10:21:02 	ppp: [wan_link0] PPPoE: connection closed
Jan 13 10:21:02 	ppp: [wan_link0] Link: DOWN event
Jan 13 10:21:02 	ppp: [wan_link0] LCP: Down event
Jan 13 10:21:02 	ppp: [wan_link0] LCP: state change Stopped --> Starting
Jan 13 10:21:02 	ppp: [wan_link0] LCP: LayerStart
Jan 13 10:21:02 	ppp: [wan_link0] Link: reconnection attempt 1 in 4 seconds

the system log does show the interface a down and then later a linkup message but it just wont reconnect and more interesting is y does the below fail

Jan 13 10:20:55 	ppp: [wan] IFACE: Delete route 0.0.0.0/0 2.48.4.1 failed: No such process

bear in mind that FTTH modem the isp has given here, when u connect the wan cable coming out of it to any machine, by default it wont get any ip at all, in windows it would try and then fail and revert to 169.x.x.x, the machine would just say cable connected but no ip on it, not even any private ip

eri-- · Jan 14, 2015, 4:03 PM

I am interested on your system log not your ppp logs.

xbipin · Jan 15, 2015, 6:12 AM

here u go, included both the logs

system log

Jan 15 10:07:38 	syslogd: kernel boot file is /boot/kernel/kernel
Jan 15 10:07:46 	kernel: vr1: link state changed to DOWN
Jan 15 10:08:43 	check_reload_status: Restarting ipsec tunnels
Jan 15 10:08:43 	check_reload_status: Restarting OpenVPN tunnels/interfaces
Jan 15 10:08:43 	check_reload_status: Reloading filter
Jan 15 10:08:46 	php-fpm[56184]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN.
Jan 15 10:08:46 	php-fpm[56184]: /rc.openvpn: OpenVPN: Resync client1 ExpressVPN
Jan 15 10:08:49 	php-fpm[56184]: /rc.openvpn: OpenVPN ID client1 PID 20721 still running, killing.
Jan 15 10:08:49 	kernel: ovpnc1: link state changed to DOWN
Jan 15 10:08:50 	check_reload_status: Reloading filter
Jan 15 10:08:53 	php-fpm[41289]: /rc.dyndns.update: phpDynDNS (firewall.domain.com): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry.
Jan 15 10:08:55 	php: rc.kill_states: rc.kill_states: Removing states for IP 86.99.125.32/32
Jan 15 10:08:55 	check_reload_status: Rewriting resolv.conf
Jan 15 10:08:59 	php-fpm[55844]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:08:59 	php-fpm[55844]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:08:59 	php-fpm[55844]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:08:59 	php-fpm[55844]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:00 	php-fpm[55844]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:00 	php-fpm[55844]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:00 	php-fpm[55844]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:00 	php-fpm[55844]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:00 	php-fpm[55844]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:00 	php-fpm[55844]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:02 	check_reload_status: Linkup starting vr1
Jan 15 10:09:02 	kernel: vr1: link state changed to UP
Jan 15 10:09:07 	php-fpm[56184]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:07 	php-fpm[56184]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:07 	php-fpm[56184]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:07 	php-fpm[56184]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:07 	php-fpm[56184]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:07 	php-fpm[56184]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:07 	php-fpm[56184]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:07 	php-fpm[56184]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:08 	php-fpm[56184]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:08 	php-fpm[56184]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 15 10:09:15 	check_reload_status: Restarting ipsec tunnels
Jan 15 10:09:20 	check_reload_status: updating dyndns wan

ppp logs

Jan 15 10:08:34 	ppp: [wan_link0] LCP: no reply to 3 echo request(s)
Jan 15 10:08:44 	ppp: [wan_link0] LCP: no reply to 4 echo request(s)
Jan 15 10:08:54 	ppp: [wan_link0] LCP: no reply to 5 echo request(s)
Jan 15 10:08:54 	ppp: [wan_link0] LCP: peer not responding to echo requests
Jan 15 10:08:54 	ppp: [wan_link0] LCP: state change Opened --> Stopping
Jan 15 10:08:54 	ppp: [wan_link0] Link: Leave bundle "wan"
Jan 15 10:08:54 	ppp: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Jan 15 10:08:54 	ppp: [wan] IPCP: Close event
Jan 15 10:08:54 	ppp: [wan] IPCP: state change Opened --> Closing
Jan 15 10:08:54 	ppp: [wan] IPCP: SendTerminateReq #4
Jan 15 10:08:54 	ppp: [wan] IPCP: LayerDown
Jan 15 10:08:55 	ppp: [wan] IFACE: Delete route 0.0.0.0/0 2.48.4.1 failed: No such process
Jan 15 10:08:55 	ppp: [wan] IFACE: Down event
Jan 15 10:08:55 	ppp: [wan] IFACE: Rename interface pppoe0 to pppoe0
Jan 15 10:08:55 	ppp: [wan] IPV6CP: Close event
Jan 15 10:08:55 	ppp: [wan] IPV6CP: state change Stopped --> Closed
Jan 15 10:08:55 	ppp: [wan] IPCP: Down event
Jan 15 10:08:55 	ppp: [wan] IPCP: LayerFinish
Jan 15 10:08:55 	ppp: [wan] Bundle: No NCPs left. Closing links...
Jan 15 10:08:55 	ppp: [wan] IPCP: state change Closing --> Initial
Jan 15 10:08:55 	ppp: [wan] IPV6CP: Down event
Jan 15 10:08:55 	ppp: [wan] IPV6CP: state change Closed --> Initial
Jan 15 10:08:55 	ppp: [wan_link0] LCP: SendTerminateReq #3
Jan 15 10:08:55 	ppp: [wan_link0] LCP: LayerDown
Jan 15 10:08:58 	ppp: [wan_link0] LCP: SendTerminateReq #4
Jan 15 10:09:00 	ppp: [wan_link0] LCP: state change Stopping --> Stopped
Jan 15 10:09:00 	ppp: [wan_link0] LCP: LayerFinish
Jan 15 10:09:00 	ppp: [wan_link0] PPPoE: connection closed
Jan 15 10:09:00 	ppp: [wan_link0] Link: DOWN event
Jan 15 10:09:00 	ppp: [wan_link0] LCP: Down event
Jan 15 10:09:00 	ppp: [wan_link0] LCP: state change Stopped --> Starting
Jan 15 10:09:00 	ppp: [wan_link0] LCP: LayerStart
Jan 15 10:09:00 	ppp: [wan_link0] Link: reconnection attempt 1 in 1 seconds
Jan 15 10:09:01 	ppp: [wan_link0] Link: reconnection attempt 1
Jan 15 10:09:01 	ppp: [wan_link0] PPPoE: Connecting to ''
Jan 15 10:09:05 	ppp: Multi-link PPP daemon for FreeBSD
Jan 15 10:09:05 	ppp:
Jan 15 10:09:05 	ppp: process 67927 started, version 5.7 (root@pfsense-22-i386-builder 13:22 18-Nov-2014)
Jan 15 10:09:05 	ppp: caught fatal signal TERM
Jan 15 10:09:05 	ppp: [wan] IFACE: Close event
Jan 15 10:09:05 	ppp: [wan] IPCP: Close event
Jan 15 10:09:05 	ppp: [wan] IPV6CP: Close event
Jan 15 10:09:05 	ppp: waiting for process 6370 to die...
Jan 15 10:09:06 	ppp: waiting for process 6370 to die...
Jan 15 10:09:07 	ppp: [wan] Bundle: Shutdown
Jan 15 10:09:07 	ppp: [wan_link0] Link: Shutdown
Jan 15 10:09:07 	ppp: process 6370 terminated
Jan 15 10:09:07 	ppp: web: web is not running
Jan 15 10:09:07 	ppp: [wan] Bundle: Interface ng0 created
Jan 15 10:09:07 	ppp: [wan_link0] Link: OPEN event
Jan 15 10:09:07 	ppp: [wan_link0] LCP: Open event
Jan 15 10:09:07 	ppp: [wan_link0] LCP: state change Initial --> Starting
Jan 15 10:09:07 	ppp: [wan_link0] LCP: LayerStart
Jan 15 10:09:07 	ppp: [wan_link0] PPPoE: Connecting to ''
Jan 15 10:09:16 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan 15 10:09:16 	ppp: [wan_link0] Link: DOWN event
Jan 15 10:09:16 	ppp: [wan_link0] LCP: Down event
Jan 15 10:09:16 	ppp: [wan_link0] Link: reconnection attempt 1 in 3 seconds
Jan 15 10:09:19 	ppp: [wan_link0] Link: reconnection attempt 1
Jan 15 10:09:19 	ppp: [wan_link0] PPPoE: Connecting to ''
Jan 15 10:09:28 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan 15 10:09:28 	ppp: [wan_link0] Link: DOWN event
Jan 15 10:09:28 	ppp: [wan_link0] LCP: Down event
Jan 15 10:09:28 	ppp: [wan_link0] Link: reconnection attempt 2 in 4 seconds
Jan 15 10:09:32 	ppp: [wan_link0] Link: reconnection attempt 2
Jan 15 10:09:32 	ppp: [wan_link0] PPPoE: Connecting to ''
Jan 15 10:09:41 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan 15 10:09:41 	ppp: [wan_link0] Link: DOWN event
Jan 15 10:09:41 	ppp: [wan_link0] LCP: Down event
Jan 15 10:09:41 	ppp: [wan_link0] Link: reconnection attempt 3 in 2 seconds
Jan 15 10:09:43 	ppp: [wan_link0] Link: reconnection attempt 3
Jan 15 10:09:43 	ppp: [wan_link0] PPPoE: Connecting to ''
Jan 15 10:09:52 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan 15 10:09:52 	ppp: [wan_link0] Link: DOWN event
Jan 15 10:09:52 	ppp: [wan_link0] LCP: Down event
Jan 15 10:09:52 	ppp: [wan_link0] Link: reconnection attempt 4 in 4 seconds
Jan 15 10:09:56 	ppp: [wan_link0] Link: reconnection attempt 4
Jan 15 10:09:56 	ppp: [wan_link0] PPPoE: Connecting to ''
Jan 15 10:10:05 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan 15 10:10:05 	ppp: [wan_link0] Link: DOWN event
Jan 15 10:10:05 	ppp: [wan_link0] LCP: Down event
Jan 15 10:10:05 	ppp: [wan_link0] Link: reconnection attempt 5 in 2 seconds

eri-- · Jan 15, 2015, 3:53 PM

From what i see seems mpd does not exit and the new instance is started.
Probably need modification to kill the first the run the other one.

xbipin · Jan 16, 2015, 6:05 AM

is there some easy fix or patch which i can test for now?

eri-- · Jan 16, 2015, 7:40 AM


diff --git a/etc/inc/interfaces.inc b/etc/inc/interfaces.inc
index cd709a9..e388498 100644
--- a/etc/inc/interfaces.inc
+++ b/etc/inc/interfaces.inc
@@ -1810,6 +1810,8 @@ EOD;
        }

        /* fire up mpd */
+       if (isvalidpid("{$g['varrun_path']}/" . escapeshellarg($ppp['type']) . "_{$interface}.pid"))
+               killbypid("{$g['varrun_path']}/" . escapeshellarg($ppp['type']) . "_{$interface}.pid");
        mwexec("/usr/local/sbin/mpd5 -b -k -d {$g['varetc_path']} -f mpd_{$interface}.conf -p {$g['varrun_path']}/" .
                escapeshellarg($ppp['type']) . "_{$interface}.pid -s ppp " . escapeshellarg($ppp['type']) . "client");

xbipin · Jan 16, 2015, 9:35 AM

well the patch works in one situation and doesnt in other, suppose if ftth modem is up and running and i pull wan plug cable from it to pfsense and then replug after sometime then connection comes back up, the other situation in which if i reset the ftth modem or power off that and repower on then while the modem is initializing, after in a few seconds the interface shows linkup and then mpd starts reconnecting but then it goes on for ever and never reconnects.

in summary, if modem is up and running and interface goes through link down and link up then it connects fine but suppose if the modem is rebooting then the interface link down and link up happens soon enough and mpd tries to reconnect but till then the modem isnt yet completely up and in that mpd never reconnects, even then when modem is completely up and i pull wan cable and reconnect then also it never reconnects unless pfsense is rebooted.

xbipin · Jan 16, 2015, 9:48 AM

i think mpd doesnt completely exit before a new one is created or something like that, probably it needs to completely exit and detach from interface before a new one is created

system log

Jan 16 13:39:43 	kernel: vr1: link state changed to DOWN
Jan 16 13:40:42 	check_reload_status: updating dyndns WAN
Jan 16 13:40:42 	check_reload_status: Restarting ipsec tunnels
Jan 16 13:40:42 	check_reload_status: Restarting OpenVPN tunnels/interfaces
Jan 16 13:40:42 	check_reload_status: Reloading filter
Jan 16 13:40:44 	php-fpm[4437]: /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use WAN.
Jan 16 13:40:44 	php-fpm[4437]: /rc.openvpn: OpenVPN: Resync client1 ExpressVPN
Jan 16 13:40:48 	php-fpm[4437]: /rc.openvpn: OpenVPN ID client1 PID 20369 still running, killing.
Jan 16 13:40:48 	kernel: ovpnc1: link state changed to DOWN
Jan 16 13:40:48 	php: rc.kill_states: rc.kill_states: Removing states for IP 2.48.5.170/32
Jan 16 13:40:48 	check_reload_status: Reloading filter
Jan 16 13:40:48 	check_reload_status: Rewriting resolv.conf
Jan 16 13:40:55 	php-fpm[4374]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:40:55 	php-fpm[4374]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:40:55 	php-fpm[4374]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:40:55 	php-fpm[4374]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:40:56 	php-fpm[4374]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:40:56 	php-fpm[4374]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:40:56 	php-fpm[4374]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:40:56 	php-fpm[4374]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:40:56 	php-fpm[4374]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:40:56 	php-fpm[4374]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:40:59 	kernel: vr1: link state changed to UP
Jan 16 13:40:59 	check_reload_status: Linkup starting vr1
Jan 16 13:41:03 	php-fpm[4437]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:41:03 	php-fpm[4437]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:41:03 	php-fpm[4437]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:41:03 	php-fpm[4437]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:41:03 	php-fpm[4437]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:41:03 	php-fpm[4437]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:41:04 	php-fpm[4437]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:41:04 	php-fpm[4437]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:41:04 	php-fpm[4437]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:41:04 	php-fpm[4437]: /rc.filter_configure_sync: Could not find IPv4 gateway for interface (wan).
Jan 16 13:41:11 	check_reload_status: Restarting ipsec tunnels
Jan 16 13:41:16 	check_reload_status: updating dyndns wan

ppp log

Jan 16 13:40:17 	ppp: [wan_link0] LCP: no reply to 2 echo request(s)
Jan 16 13:40:27 	ppp: [wan_link0] LCP: no reply to 3 echo request(s)
Jan 16 13:40:37 	ppp: [wan_link0] LCP: no reply to 4 echo request(s)
Jan 16 13:40:47 	ppp: [wan_link0] LCP: no reply to 5 echo request(s)
Jan 16 13:40:47 	ppp: [wan_link0] LCP: peer not responding to echo requests
Jan 16 13:40:47 	ppp: [wan_link0] LCP: state change Opened --> Stopping
Jan 16 13:40:47 	ppp: [wan_link0] Link: Leave bundle "wan"
Jan 16 13:40:47 	ppp: [wan] Bundle: Status update: up 0 links, total bandwidth 9600 bps
Jan 16 13:40:47 	ppp: [wan] IPCP: Close event
Jan 16 13:40:47 	ppp: [wan] IPCP: state change Opened --> Closing
Jan 16 13:40:47 	ppp: [wan] IPCP: SendTerminateReq #4
Jan 16 13:40:47 	ppp: [wan] IPCP: LayerDown
Jan 16 13:40:48 	ppp: [wan] IFACE: Delete route 0.0.0.0/0 2.48.4.1 failed: No such process
Jan 16 13:40:48 	ppp: [wan] IFACE: Down event
Jan 16 13:40:48 	ppp: [wan] IFACE: Rename interface pppoe0 to pppoe0
Jan 16 13:40:48 	ppp: [wan] IPV6CP: Close event
Jan 16 13:40:48 	ppp: [wan] IPV6CP: state change Stopped --> Closed
Jan 16 13:40:48 	ppp: [wan] IPCP: Down event
Jan 16 13:40:48 	ppp: [wan] IPCP: LayerFinish
Jan 16 13:40:48 	ppp: [wan] Bundle: No NCPs left. Closing links...
Jan 16 13:40:48 	ppp: [wan] IPCP: state change Closing --> Initial
Jan 16 13:40:48 	ppp: [wan] IPV6CP: Down event
Jan 16 13:40:48 	ppp: [wan] IPV6CP: state change Closed --> Initial
Jan 16 13:40:48 	ppp: [wan_link0] LCP: SendTerminateReq #3
Jan 16 13:40:48 	ppp: [wan_link0] LCP: LayerDown
Jan 16 13:40:52 	ppp: [wan_link0] LCP: SendTerminateReq #4
Jan 16 13:40:54 	ppp: [wan_link0] LCP: state change Stopping --> Stopped
Jan 16 13:40:54 	ppp: [wan_link0] LCP: LayerFinish
Jan 16 13:40:54 	ppp: [wan_link0] PPPoE: connection closed
Jan 16 13:40:54 	ppp: [wan_link0] Link: DOWN event
Jan 16 13:40:54 	ppp: [wan_link0] LCP: Down event
Jan 16 13:40:54 	ppp: [wan_link0] LCP: state change Stopped --> Starting
Jan 16 13:40:54 	ppp: [wan_link0] LCP: LayerStart
Jan 16 13:40:54 	ppp: [wan_link0] Link: reconnection attempt 1 in 1 seconds
Jan 16 13:40:55 	ppp: [wan_link0] Link: reconnection attempt 1
Jan 16 13:40:55 	ppp: [wan_link0] PPPoE: Connecting to ''
Jan 16 13:41:01 	ppp: Multi-link PPP daemon for FreeBSD
Jan 16 13:41:01 	ppp:
Jan 16 13:41:01 	ppp: process 14494 started, version 5.7 (root@pfsense-22-i386-builder 13:22 18-Nov-2014)
Jan 16 13:41:01 	ppp: caught fatal signal TERM
Jan 16 13:41:01 	ppp: [wan] IFACE: Close event
Jan 16 13:41:01 	ppp: [wan] IPCP: Close event
Jan 16 13:41:01 	ppp: [wan] IPV6CP: Close event
Jan 16 13:41:01 	ppp: waiting for process 5956 to die...
Jan 16 13:41:02 	ppp: waiting for process 5956 to die...
Jan 16 13:41:03 	ppp: [wan] Bundle: Shutdown
Jan 16 13:41:03 	ppp: [wan_link0] Link: Shutdown
Jan 16 13:41:03 	ppp: process 5956 terminated
Jan 16 13:41:03 	ppp: web: web is not running
Jan 16 13:41:03 	ppp: [wan] Bundle: Interface ng0 created
Jan 16 13:41:03 	ppp: [wan_link0] Link: OPEN event
Jan 16 13:41:03 	ppp: [wan_link0] LCP: Open event
Jan 16 13:41:03 	ppp: [wan_link0] LCP: state change Initial --> Starting
Jan 16 13:41:03 	ppp: [wan_link0] LCP: LayerStart
Jan 16 13:41:03 	ppp: [wan_link0] PPPoE: Connecting to ''
Jan 16 13:41:12 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan 16 13:41:12 	ppp: [wan_link0] Link: DOWN event
Jan 16 13:41:12 	ppp: [wan_link0] LCP: Down event
Jan 16 13:41:12 	ppp: [wan_link0] Link: reconnection attempt 1 in 4 seconds
Jan 16 13:41:16 	ppp: [wan_link0] Link: reconnection attempt 1
Jan 16 13:41:16 	ppp: [wan_link0] PPPoE: Connecting to ''
Jan 16 13:41:25 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan 16 13:41:25 	ppp: [wan_link0] Link: DOWN event
Jan 16 13:41:25 	ppp: [wan_link0] LCP: Down event
Jan 16 13:41:25 	ppp: [wan_link0] Link: reconnection attempt 2 in 4 seconds
Jan 16 13:41:29 	ppp: [wan_link0] Link: reconnection attempt 2
Jan 16 13:41:29 	ppp: [wan_link0] PPPoE: Connecting to ''
Jan 16 13:41:38 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan 16 13:41:38 	ppp: [wan_link0] Link: DOWN event
Jan 16 13:41:38 	ppp: [wan_link0] LCP: Down event
Jan 16 13:41:38 	ppp: [wan_link0] Link: reconnection attempt 3 in 3 seconds
Jan 16 13:41:41 	ppp: [wan_link0] Link: reconnection attempt 3
Jan 16 13:41:41 	ppp: [wan_link0] PPPoE: Connecting to ''
Jan 16 13:41:50 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan 16 13:41:50 	ppp: [wan_link0] Link: DOWN event
Jan 16 13:41:50 	ppp: [wan_link0] LCP: Down event
Jan 16 13:41:50 	ppp: [wan_link0] Link: reconnection attempt 4 in 4 seconds
Jan 16 13:41:54 	ppp: [wan_link0] Link: reconnection attempt 4
Jan 16 13:41:54 	ppp: [wan_link0] PPPoE: Connecting to ''

Jan 16 13:43:43 	ppp: [wan_link0] Link: DOWN event
Jan 16 13:43:43 	ppp: [wan_link0] LCP: Down event
Jan 16 13:43:43 	ppp: [wan_link0] Link: reconnection attempt 14 in 1 seconds
Jan 16 13:43:44 	ppp: [wan_link0] Link: reconnection attempt 14
Jan 16 13:43:44 	ppp: [wan_link0] PPPoE: Connecting to ''
Jan 16 13:43:53 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan 16 13:43:53 	ppp: [wan_link0] Link: DOWN event
Jan 16 13:43:53 	ppp: [wan_link0] LCP: Down event
Jan 16 13:43:53 	ppp: [wan_link0] Link: reconnection attempt 15 in 1 seconds
Jan 16 13:43:54 	ppp: [wan_link0] Link: reconnection attempt 15
Jan 16 13:43:54 	ppp: [wan_link0] PPPoE: Connecting to ''
Jan 16 13:44:03 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan 16 13:44:03 	ppp: [wan_link0] Link: DOWN event
Jan 16 13:44:03 	ppp: [wan_link0] LCP: Down event
Jan 16 13:44:03 	ppp: [wan_link0] Link: reconnection attempt 16 in 4 seconds
Jan 16 13:44:07 	ppp: [wan_link0] Link: reconnection attempt 16
Jan 16 13:44:07 	ppp: [wan_link0] PPPoE: Connecting to ''
Jan 16 13:44:16 	ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Jan 16 13:44:16 	ppp: [wan_link0] Link: DOWN event
Jan 16 13:44:16 	ppp: [wan_link0] LCP: Down event
Jan 16 13:44:16 	ppp: [wan_link0] Link: reconnection attempt 17 in 2 seconds
Jan 16 13:44:18 	ppp: [wan_link0] Link: reconnection attempt 17
Jan 16 13:44:18 	ppp: [wan_link0] PPPoE: Connecting to ''

eri-- · Jan 16, 2015, 2:54 PM

Try putting a sleep(5) after the killbypid call.

xbipin · Jan 16, 2015, 3:44 PM

@ermal:

Try putting a sleep(5) after the killbypid call.

ill try that but i think the if statement doesnt come out true so probably its not killing mpd because the logs appear same before and after the patch plus even with modem up after some while and i try cable unplug and replug it still wont work

xbipin · Jan 17, 2015, 8:48 AM

i tried sleep as well as that if statement i put in some logging and it seems that if statement never turns out to be true so the kill command isnt executed

doktornotor · Jan 17, 2015, 8:29 AM

@xbipin:

i tried sleep as well as that if statement i put in some logging and it seems that if statement never turns out to be true so the kill command isnt exucuted

Did you try leaving out the PID check and running sigkillbyname() or killbyname() instead? (Don't think checking PIDs is the best idea around in similar messy state.)

xbipin · Jan 17, 2015, 8:48 AM

@doktornotor:

@xbipin:

i tried sleep as well as that if statement i put in some logging and it seems that if statement never turns out to be true so the kill command isnt exucuted

Did you try leaving out the PID check and running sigkillbyname() or killbyname() instead? (Don't think checking PIDs is the best idea around in similar messy state.)

can u provide a replacement line for the below as im not aware of the possible functions created

killbypid("{$g['varrun_path']}/" . escapeshellarg($ppp['type']) . "_{$interface}.pid");