Pfsense / DSL / pppoe on WAN loose connection



  • pfSense 1.0.1-last-CVS

    ADSL2+ Dlink DSL-320T modem, configured in bridge modem (RFC1483 IP LLC), connected to my Pfsense WAN.

    Pfsense is configured to establish a PPPoE connection.

    ISP, Telecom Italia, "Alice" adsl (consumer level).

    Problem: From time to time (sometimes, even quite often every 5 or 20 minutes), my pfSense looses the PPPoE connection, and reestablishes
    it again. The connection isn´t unstable if I connected the modem directly to a computer - which makes me exclude that the ISP is the problem.

    Here is the log, from the "system" section:

    long - 200 lines

    Jan 7 10:36:38 dnsmasq[9534]: using nameserver 85.37.17.43#53
    Jan 7 10:36:38 dnsmasq[9534]: reading /etc/resolv.conf
    Jan 7 10:33:31 php: : phpDynDNS: (Success) IP Address Changed Successfully!
    Jan 7 10:33:31 php: : phpDynDNS: updating cache file /cf/conf/dyndns.cache: 87.4.26.142
    Jan 7 10:33:31 php: : DynDns: Current Service: dyndns-custom
    Jan 7 10:33:31 php: : DynDns: DynDns _checkStatus() starting.
    Jan 7 10:33:30 php: : DynDns: DynDns _update() starting.
    Jan 7 10:33:30 php: : DynDns: cacheIP != wan_ip. Updating.
    Jan 7 10:33:30 php: : DynDns: Cached IP: 87.4.244.209
    Jan 7 10:33:30 php: : DynDns: Current WAN IP: 87.4.26.142
    Jan 7 10:33:30 php: : DynDns: _detectChange() starting.
    Jan 7 10:33:30 php: : DynDns: updatedns() starting
    Jan 7 10:33:30 php: : DynDns: Running updatedns()
    Jan 7 10:33:27 check_reload_status: updating dyndns
    Jan 7 10:33:20 check_reload_status: reloading filter
    Jan 7 10:33:20 php: : Configuring slbd
    Jan 7 10:33:20 php: : Resyncing configuration for all packages.
    Jan 7 10:33:16 php: : Creating rrd update script
    Jan 7 10:33:16 php: : Informational: DHClient spawned /etc/rc.newwanip and the new ip is wan - 87.4.26.142.
    Jan 7 10:33:14 php: : Informational: rc.newwanip is starting.
    Jan 7 10:33:12 check_reload_status: rc.newwanip starting
    Jan 7 10:33:10 mpd: 87.4.26.142 -> 217.141.109.24
    Jan 7 10:33:10 mpd: PRIDNS 85.37.17.43
    Jan 7 10:33:10 mpd: IPADDR 87.4.26.142
    Jan 7 10:33:10 mpd: PRIDNS 85.37.17.43
    Jan 7 10:33:10 mpd: IPADDR 87.4.26.142
    Jan 7 10:33:10 mpd: PRIDNS 85.37.17.43
    Jan 7 10:33:10 mpd: 87.4.26.142 is OK
    Jan 7 10:33:10 mpd: IPADDR 87.4.26.142
    Jan 7 10:33:10 mpd: PRIDNS 0.0.0.0
    Jan 7 10:33:10 mpd: IPADDR 0.0.0.0
    Jan 7 10:33:10 mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
    Jan 7 10:33:10 mpd: IPADDR 217.141.109.24
    Jan 7 10:33:10 mpd: 217.141.109.24 is OK
    Jan 7 10:33:10 mpd: IPADDR 217.141.109.24
    Jan 7 10:33:10 mpd: PRIDNS 0.0.0.0
    Jan 7 10:33:10 mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
    Jan 7 10:33:10 mpd: IPADDR 0.0.0.0
    Jan 7 10:33:10 mpd: MAGICNUM fbf972ce
    Jan 7 10:33:10 mpd: MRU 1492
    Jan 7 10:33:10 mpd: MAGICNUM 3a62db88
    Jan 7 10:33:10 mpd: AUTHPROTO PAP
    Jan 7 10:33:10 mpd: MRU 1492
    Jan 7 10:33:10 mpd: MAGICNUM 3a62db88
    Jan 7 10:33:10 mpd: AUTHPROTO PAP
    Jan 7 10:33:10 mpd: MRU 1492
    Jan 7 10:33:09 mpd: MAGICNUM fbf972ce
    Jan 7 10:33:09 mpd: MRU 1492
    Jan 7 10:31:41 php: : phpDynDNS: (Success) IP Address Changed Successfully!
    Jan 7 10:31:41 php: : phpDynDNS: updating cache file /cf/conf/dyndns.cache: 87.4.244.209
    Jan 7 10:31:41 php: : DynDns: Current Service: dyndns-custom
    Jan 7 10:31:41 php: : DynDns: DynDns _checkStatus() starting.
    Jan 7 10:31:39 php: : DynDns: DynDns _update() starting.
    Jan 7 10:31:39 php: : DynDns: cacheIP != wan_ip. Updating.
    Jan 7 10:31:39 php: : DynDns: Cached IP: 87.8.245.83
    Jan 7 10:31:39 php: : DynDns: Current WAN IP: 87.4.244.209
    Jan 7 10:31:39 php: : DynDns: _detectChange() starting.
    Jan 7 10:31:39 php: : DynDns: updatedns() starting
    Jan 7 10:31:38 php: : DynDns: Running updatedns()
    Jan 7 10:31:36 check_reload_status: updating dyndns
    Jan 7 10:31:29 check_reload_status: reloading filter
    Jan 7 10:31:29 php: : Configuring slbd
    Jan 7 10:31:29 php: : Resyncing configuration for all packages.
    Jan 7 10:31:25 php: : Creating rrd update script
    Jan 7 10:31:25 php: : Informational: DHClient spawned /etc/rc.newwanip and the new ip is wan - 87.4.244.209.
    Jan 7 10:31:22 php: : Informational: rc.newwanip is starting.
    Jan 7 10:31:21 check_reload_status: rc.newwanip starting
    Jan 7 10:31:17 mpd: 87.4.244.209 -> 217.141.109.24
    Jan 7 10:31:17 mpd: PRIDNS 85.37.17.43
    Jan 7 10:31:17 mpd: IPADDR 87.4.244.209
    Jan 7 10:31:17 mpd: PRIDNS 85.37.17.43
    Jan 7 10:31:17 mpd: IPADDR 87.4.244.209
    Jan 7 10:31:17 mpd: PRIDNS 85.37.17.43
    Jan 7 10:31:17 mpd: 87.4.244.209 is OK
    Jan 7 10:31:17 mpd: IPADDR 87.4.244.209
    Jan 7 10:31:17 mpd: PRIDNS 0.0.0.0
    Jan 7 10:31:17 mpd: IPADDR 0.0.0.0
    Jan 7 10:31:17 mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
    Jan 7 10:31:17 mpd: IPADDR 217.141.109.24
    Jan 7 10:31:17 mpd: 217.141.109.24 is OK
    Jan 7 10:31:17 mpd: IPADDR 217.141.109.24
    Jan 7 10:31:17 mpd: PRIDNS 0.0.0.0
    Jan 7 10:31:17 mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
    Jan 7 10:31:17 mpd: IPADDR 0.0.0.0
    Jan 7 10:31:16 mpd: MAGICNUM f70a96b0
    Jan 7 10:31:16 mpd: MRU 1492
    Jan 7 10:31:16 mpd: MAGICNUM 7f43214f
    Jan 7 10:31:16 mpd: AUTHPROTO PAP
    Jan 7 10:31:16 mpd: MRU 1492
    Jan 7 10:31:16 mpd: MAGICNUM 7f43214f
    Jan 7 10:31:16 mpd: AUTHPROTO PAP
    Jan 7 10:31:16 mpd: MRU 1492
    Jan 7 10:31:16 mpd: MAGICNUM f70a96b0
    Jan 7 10:31:16 mpd: MRU 1492
    Jan 7 10:03:26 php: : phpDynDNS: (Unknown Response)
    Jan 7 10:03:26 php: : phpDynDNS: PAYLOAD:
    Jan 7 10:03:26 php: : DynDns: Current Service: dyndns-custom
    Jan 7 10:03:26 php: : DynDns: DynDns _checkStatus() starting.
    Jan 7 10:03:26 php: : Curl errror occured: Couldn't resolve host 'members.dyndns.org'
    Jan 7 10:02:40 php: : DynDns: DynDns _update() starting.
    Jan 7 10:02:40 php: : DynDns: cacheIP != wan_ip. Updating.
    Jan 7 10:02:40 php: : DynDns: Cached IP: 87.8.245.83
    Jan 7 10:02:40 php: : DynDns: Current WAN IP: 87.9.245.57
    Jan 7 10:02:40 php: : DynDns: _detectChange() starting.
    Jan 7 10:02:40 php: : DynDns: updatedns() starting
    Jan 7 10:02:40 php: : DynDns: Running updatedns()
    Jan 7 10:02:38 check_reload_status: updating dyndns
    Jan 7 10:02:31 check_reload_status: reloading filter
    Jan 7 10:02:31 php: : Configuring slbd
    Jan 7 10:02:31 php: : Resyncing configuration for all packages.
    Jan 7 10:02:28 dnsmasq[9534]: using nameserver 85.37.17.43#53
    Jan 7 10:02:28 dnsmasq[9534]: reading /etc/resolv.conf
    Jan 7 10:02:27 php: : Creating rrd update script
    Jan 7 10:02:27 php: : Informational: DHClient spawned /etc/rc.newwanip and the new ip is wan - 87.9.245.57.
    Jan 7 10:02:25 php: : Informational: rc.newwanip is starting.
    Jan 7 10:02:23 check_reload_status: rc.newwanip starting
    Jan 7 10:02:20 mpd: 87.9.245.57 -> 217.141.109.24
    Jan 7 10:02:20 mpd: PRIDNS 85.37.17.43
    Jan 7 10:02:20 mpd: IPADDR 87.9.245.57
    Jan 7 10:02:20 mpd: PRIDNS 85.37.17.43
    Jan 7 10:02:20 mpd: IPADDR 87.9.245.57
    Jan 7 10:02:20 mpd: PRIDNS 85.37.17.43
    Jan 7 10:02:20 mpd: 87.9.245.57 is OK
    Jan 7 10:02:20 mpd: IPADDR 87.9.245.57
    Jan 7 10:02:20 mpd: PRIDNS 0.0.0.0
    Jan 7 10:02:20 mpd: IPADDR 0.0.0.0
    Jan 7 10:02:20 mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
    Jan 7 10:02:20 mpd: IPADDR 217.141.109.24
    Jan 7 10:02:20 mpd: 217.141.109.24 is OK
    Jan 7 10:02:20 mpd: IPADDR 217.141.109.24
    Jan 7 10:02:20 mpd: PRIDNS 0.0.0.0
    Jan 7 10:02:20 mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
    Jan 7 10:02:20 mpd: IPADDR 0.0.0.0
    Jan 7 10:02:20 mpd: MAGICNUM efeab556
    Jan 7 10:02:20 mpd: MRU 1492
    Jan 7 10:02:20 mpd: MAGICNUM 58814b9d
    Jan 7 10:02:20 mpd: AUTHPROTO PAP
    Jan 7 10:02:20 mpd: MRU 1492
    Jan 7 10:02:20 mpd: MAGICNUM 58814b9d
    Jan 7 10:02:20 mpd: AUTHPROTO PAP
    Jan 7 10:02:20 mpd: MRU 1492
    Jan 7 10:02:20 mpd: MAGICNUM efeab556
    Jan 7 10:02:20 mpd: MRU 1492
    Jan 7 09:56:30 dnsmasq[9534]: using nameserver 85.37.17.43#53
    Jan 7 09:56:30 dnsmasq[9534]: reading /etc/resolv.conf
    Jan 7 09:50:51 php: : phpDynDNS: (Success) IP Address Changed Successfully!
    Jan 7 09:50:51 php: : phpDynDNS: updating cache file /cf/conf/dyndns.cache: 87.8.245.83
    Jan 7 09:50:51 php: : DynDns: Current Service: dyndns-custom
    Jan 7 09:50:51 php: : DynDns: DynDns _checkStatus() starting.
    Jan 7 09:50:50 php: : DynDns: DynDns _update() starting.
    Jan 7 09:50:50 php: : DynDns: cacheIP != wan_ip. Updating.
    Jan 7 09:50:50 php: : DynDns: Cached IP: 87.8.245.192
    Jan 7 09:50:50 php: : DynDns: Current WAN IP: 87.8.245.83
    Jan 7 09:50:50 php: : DynDns: _detectChange() starting.
    Jan 7 09:50:50 php: : DynDns: updatedns() starting
    Jan 7 09:50:50 php: : DynDns: Running updatedns()
    Jan 7 09:50:47 check_reload_status: updating dyndns
    Jan 7 09:50:40 check_reload_status: reloading filter
    Jan 7 09:50:40 php: : Configuring slbd
    Jan 7 09:50:40 php: : Resyncing configuration for all packages.
    Jan 7 09:50:36 php: : Creating rrd update script
    Jan 7 09:50:36 php: : Informational: DHClient spawned /etc/rc.newwanip and the new ip is wan - 87.8.245.83.
    Jan 7 09:50:33 php: : Informational: rc.newwanip is starting.
    Jan 7 09:50:31 check_reload_status: rc.newwanip starting
    Jan 7 09:50:28 mpd: 87.8.245.83 -> 217.141.109.24
    Jan 7 09:50:28 mpd: IPADDR 217.141.109.24
    Jan 7 09:50:28 mpd: 217.141.109.24 is OK
    Jan 7 09:50:28 mpd: IPADDR 217.141.109.24
    Jan 7 09:50:27 mpd: PRIDNS 85.37.17.43
    Jan 7 09:50:27 mpd: IPADDR 87.8.245.83
    Jan 7 09:50:27 mpd: PRIDNS 85.37.17.43
    Jan 7 09:50:27 mpd: IPADDR 87.8.245.83
    Jan 7 09:50:25 mpd: PRIDNS 85.37.17.43
    Jan 7 09:50:25 mpd: IPADDR 87.8.245.83
    Jan 7 09:50:25 mpd: PRIDNS 85.37.17.43
    Jan 7 09:50:25 mpd: 87.8.245.83 is OK
    Jan 7 09:50:25 mpd: IPADDR 87.8.245.83
    Jan 7 09:50:25 mpd: PRIDNS 0.0.0.0
    Jan 7 09:50:25 mpd: IPADDR 0.0.0.0
    Jan 7 09:50:25 mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
    Jan 7 09:50:25 mpd: PRIDNS 0.0.0.0
    Jan 7 09:50:25 mpd: COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
    Jan 7 09:50:25 mpd: IPADDR 0.0.0.0
    Jan 7 09:50:24 mpd: MAGICNUM fa576fce
    Jan 7 09:50:24 mpd: MRU 1492
    Jan 7 09:50:24 mpd: MAGICNUM 113f7b85
    Jan 7 09:50:24 mpd: AUTHPROTO PAP
    Jan 7 09:50:24 mpd: MRU 1492
    Jan 7 09:50:24 mpd: MAGICNUM 113f7b85
    Jan 7 09:50:24 mpd: AUTHPROTO PAP
    Jan 7 09:50:24 mpd: MRU 1492
    Jan 7 09:50:24 mpd: MAGICNUM fa576fce
    Jan 7 09:50:24 mpd: MRU 1492
    Jan 7 09:50:23 mpd: MAGICNUM 6dcb24e4
    Jan 7 09:50:23 mpd: AUTHPROTO PAP
    Jan 7 09:50:23 mpd: MRU 1492
    Jan 7 09:50:23 mpd: MAGICNUM 6dcb24e4
    Jan 7 09:50:23 mpd: AUTHPROTO PAP
    Jan 7 09:50:23 mpd: MRU 1492
    Jan 7 09:50:22 mpd: MAGICNUM fa576fce

    ** end 200 lines **

    /gbosco



  • Make sure you have the 'Dial on Demand' option unchecked under Interfaces>WAN, PPPoE configuration.



  • "Dial on Demand" was already unchecked.

    I digged more into the logs, and found out that:

    ** little selected snippet **

    Jan  8 10:24:09 6senso mpd: [pppoe] LCP: no reply to 1 echo request(s)
    Jan  8 10:24:19 6senso mpd: [pppoe] LCP: no reply to 2 echo request(s)
    Jan  8 10:25:29 6senso mpd: [pppoe] LCP: no reply to 1 echo request(s)
    Jan  8 10:25:39 6senso mpd: [pppoe] LCP: no reply to 2 echo request(s)
    Jan  8 10:25:49 6senso mpd: [pppoe] LCP: no reply to 3 echo request(s)
    Jan  8 10:25:59 6senso mpd: [pppoe] LCP: no reply to 4 echo request(s)
    Jan  8 10:26:09 6senso mpd: [pppoe] LCP: no reply to 5 echo request(s)
    Jan  8 10:26:09 6senso mpd: [pppoe] LCP: peer not responding to echo requests
    Jan  8 10:26:09 6senso mpd: [pppoe] LCP: LayerFinish

    ** end selected snippet **

    from time to time MPD, sends out this LCP echo packets, and for some reason - does not receive any answer from my ISP. MPD then - decide to bring
    down my PPPoE connection, to take it up again after few seconds. This changes my public IP, and disrupts temporarily connectivity.

    I´m evaluating whether to disable LCP requests from MPD.

    What could that be the effects, of such a course of action?

    /gbosco



  • Watch your modem. If you have a bad line it might go to training mode during that time. Maybe the other OS that you tried simply uses longer timeouts before it disconnects the session and does a reconnect.



  • modified /var/etc/mpd.conf, and set a more generous timing when MPD determines LCP echo timeout.


    set link keep-alive 30 300

    (it was: set link keep-alive 10 60)


    I didn´t loose the connection for more than 24 hours now - which is a record!

    I would wish pfSense had a feature under PPPoE, where it is possible to set those values.

    Thanks to anyone who participated to this thread.

    /gbosco


Locked