Netgate Discussion Forum
    • Categories
    • Recent
    • Tags
    • Popular
    • Users
    • Search
    • Register
    • Login

    [2.3.x] No default route on WAN PPPoE after link failure (with FIX, please test)

    Scheduled Pinned Locked Moved Problems Installing or Upgrading pfSense Software
    42 Posts 7 Posters 13.6k Views
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • M
      Marlenio
      last edited by

      Hi cmb,

      @cmb:

      […]
      add this line:

      log_error("DEBUG: interface: $interface interfacegw: $interfacegw gatewayip: $gatewayip");

      Then replicate again, and post the new logs.

      I change /etc/inc/system.inc:

      
        /* La linea seguente è stata aggiunta per il debug dell'errore Redmine #6495 */
        log_error("DEBUG: interface: $interface interfacegw: $interfacegw gatewayip: $gatewayip");         
	if ($dont_add_route == false) {
		if (!empty($interface) && $interface != $interfacegw) {

      This is system log with  strictly stock source:

      
Jun 24 10:38:03	xinetd	14152	Reconfigured: new=0 old=1 dropped=0 (services)
Jun 24 10:38:03	xinetd	14152	readjusting service 6969-udp
Jun 24 10:38:03	xinetd	14152	Swapping defaults
Jun 24 10:38:03	xinetd	14152	Starting reconfiguration
Jun 24 10:38:02	xinetd	14152	Reconfigured: new=0 old=1 dropped=0 (services)
Jun 24 10:38:02	xinetd	14152	readjusting service 6969-udp
Jun 24 10:38:02	xinetd	14152	Swapping defaults
Jun 24 10:38:02	xinetd	14152	Starting reconfiguration
Jun 24 10:38:01	ftp-proxy	5586	listening on 127.0.0.1 port 8021
Jun 24 10:38:01	check_reload_status		Reloading filter
Jun 24 10:38:01	check_reload_status		Syncing firewall
Jun 24 10:38:01	php-fpm	98299	[pfBlockerNG] Starting cron process.
Jun 24 10:38:01	ftp-proxy	2171	listening on 127.0.0.1 port 8021
Jun 24 10:38:01	check_reload_status		Reloading filter
Jun 24 10:38:01	php-fpm	98299	/rc.start_packages: Restarting/Starting all packages.
Jun 24 10:38:00	check_reload_status		Starting packages
Jun 24 10:38:00	php-fpm	65464	/rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 79.47.194.62 -> 79.56.147.131 - Restarting packages.
Jun 24 10:37:59	xinetd	14152	Reconfigured: new=0 old=1 dropped=0 (services)
Jun 24 10:37:59	xinetd	14152	readjusting service 6969-udp
Jun 24 10:37:59	xinetd	14152	Swapping defaults
Jun 24 10:37:59	xinetd	14152	Starting reconfiguration
Jun 24 10:37:58	php-fpm	65464	/rc.newwanip: Creating rrd update script
Jun 24 10:37:58	php-fpm	65464	/rc.newwanip: Resyncing OpenVPN instances for interface WAN.
Jun 24 10:37:58	check_reload_status		Reloading filter
Jun 24 10:37:58	php-fpm	65464	/rc.newwanip: Forcefully reloading IPsec
Jun 24 10:37:57	php-fpm	65464	/rc.newwanip: Curl error occurred: Could not resolve host: ipv4.tunnelbroker.net
Jun 24 10:37:54	xinetd	14152	Reconfigured: new=0 old=1 dropped=0 (services)
Jun 24 10:37:54	xinetd	14152	readjusting service 6969-udp
Jun 24 10:37:54	xinetd	14152	Swapping defaults
Jun 24 10:37:54	xinetd	14152	Starting reconfiguration
Jun 24 10:37:53	check_reload_status		Reloading filter
Jun 24 10:37:53	php-fpm	55525	/rc.newipsecdns: IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
Jun 24 10:37:51	xinetd	14152	Reconfigured: new=0 old=1 dropped=0 (services)
Jun 24 10:37:51	xinetd	14152	readjusting service 6969-udp
Jun 24 10:37:51	xinetd	14152	Swapping defaults
Jun 24 10:37:51	xinetd	14152	Starting reconfiguration
Jun 24 10:37:50	xinetd	14152	Reconfigured: new=0 old=1 dropped=0 (services)
Jun 24 10:37:50	xinetd	14152	readjusting service 6969-udp
Jun 24 10:37:50	xinetd	14152	Swapping defaults
Jun 24 10:37:50	xinetd	14152	Starting reconfiguration
Jun 24 10:37:49	xinetd	14152	Reconfigured: new=0 old=1 dropped=0 (services)
Jun 24 10:37:49	xinetd	14152	readjusting service 6969-udp
Jun 24 10:37:49	xinetd	14152	Swapping defaults
Jun 24 10:37:49	xinetd	14152	Starting reconfiguration
Jun 24 10:37:48	php-fpm	74632	/rc.dyndns.update: Curl error occurred: Could not resolve host: ipv4.tunnelbroker.net
Jun 24 10:37:47	php-fpm	65464	/rc.newwanip: Curl error occurred: Could not resolve host: freedns.afraid.org
Jun 24 10:37:47	php-fpm	65464	/rc.newwanip: Dynamic DNS freedns (casalener.mooo.com): _checkStatus() starting.
Jun 24 10:37:38	php-fpm	65464	/rc.newwanip: Dynamic DNS freedns (casalener.mooo.com): _update() starting.
Jun 24 10:37:38	php-fpm	65464	/rc.newwanip: DynDns (casalener.mooo.com): Dynamic Dns: cacheIP != wan_ip. Updating. Cached IP: 80.181.221.144 WAN IP: 79.56.147.131
Jun 24 10:37:38	php-fpm	65464	/rc.newwanip: Dynamic Dns (casalener.mooo.com): Current WAN IP: 79.56.147.131 Cached IP: 80.181.221.144
Jun 24 10:37:38	php-fpm	65464	/rc.newwanip: Dynamic DNS freedns (casalener.mooo.com): 79.56.147.131 extracted from local system.
Jun 24 10:37:38	php-fpm	65464	/rc.newwanip: Dynamic DNS (casalener.mooo.com): running get_failover_interface for wan. found pppoe1
Jun 24 10:37:38	php-fpm	65464	/rc.newwanip: Dynamic DNS freedns (casalener.mooo.com): 79.56.147.131 extracted from local system.
Jun 24 10:37:38	php-fpm	65464	/rc.newwanip: Dynamic DNS: updatedns() starting
Jun 24 10:37:38	php-fpm	74632	/rc.dyndns.update: Curl error occurred: Could not resolve host: freedns.afraid.org
Jun 24 10:37:38	php-fpm	74632	/rc.dyndns.update: Dynamic DNS freedns (casalener.mooo.com): _checkStatus() starting.
Jun 24 10:37:38	check_reload_status		Reloading filter
Jun 24 10:37:38	php-fpm	55525	/rc.newipsecdns: IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
Jun 24 10:37:37	php-fpm	65464	/rc.newwanip: Curl error occurred: Could not resolve host: dynupdate.no-ip.com
Jun 24 10:37:29	php-fpm	74632	/rc.dyndns.update: Dynamic DNS freedns (casalener.mooo.com): _update() starting.
Jun 24 10:37:29	php-fpm	74632	/rc.dyndns.update: DynDns (casalener.mooo.com): Dynamic Dns: cacheIP != wan_ip. Updating. Cached IP: 80.181.221.144 WAN IP: 79.56.147.131
Jun 24 10:37:29	php-fpm	74632	/rc.dyndns.update: Dynamic Dns (casalener.mooo.com): Current WAN IP: 79.56.147.131 Cached IP: 80.181.221.144
Jun 24 10:37:29	php-fpm	74632	/rc.dyndns.update: Dynamic DNS freedns (casalener.mooo.com): 79.56.147.131 extracted from local system.
Jun 24 10:37:29	php-fpm	74632	/rc.dyndns.update: Dynamic DNS (casalener.mooo.com): running get_failover_interface for wan. found pppoe1
Jun 24 10:37:29	php-fpm	74632	/rc.dyndns.update: Dynamic DNS freedns (casalener.mooo.com): 79.56.147.131 extracted from local system.
Jun 24 10:37:29	php-fpm	74632	/rc.dyndns.update: Dynamic DNS: updatedns() starting
Jun 24 10:37:28	php-fpm	74632	/rc.dyndns.update: Curl error occurred: Could not resolve host: dynupdate.no-ip.com
Jun 24 10:37:23	php-fpm	55525	/status_interfaces.php: ROUTING: setting IPv6 default route to 2001:470:1f12:62c::1
Jun 24 10:37:23	kernel		gif0: link state changed to UP
Jun 24 10:37:23	kernel		gif0: link state changed to DOWN
Jun 24 10:37:23	php-fpm	55525	/status_interfaces.php: DEBUG: interface: opt1 interfacegw: wan gatewayip:
Jun 24 10:37:19	check_reload_status		Reloading filter
Jun 24 10:37:19	check_reload_status		Restarting OpenVPN tunnels/interfaces
Jun 24 10:37:19	check_reload_status		Reloading filter
Jun 24 10:37:19	check_reload_status		Restarting ipsec tunnels
Jun 24 10:37:19	check_reload_status		Restarting OpenVPN tunnels/interfaces
Jun 24 10:37:19	check_reload_status		updating dyndns HE_IPV6_TUNNELV6
Jun 24 10:37:19	check_reload_status		Restarting ipsec tunnels
Jun 24 10:37:19	check_reload_status		updating dyndns WAN_PPPOE
Jun 24 10:37:16	ppp		[wan] IPV6CP: LayerFinish
Jun 24 10:37:16	ppp		[wan] IPV6CP: state change Stopping --> Stopped
Jun 24 10:37:16	php-fpm	65464	/rc.newwanip: Removing static route for monitor 2001:4860:4860::8888 and adding a new route through 2001:470:1f12:62c::1
Jun 24 10:37:16	php-fpm	65464	/rc.newwanip: DEBUG: interface: wan interfacegw: wan gatewayip:
Jun 24 10:37:15	php-fpm	74632	/rc.resolv_conf_generate: The command '/sbin/route delete -host 208.67.220.220 ' returned exit code '1', the output was 'route: writing to routing socket: No such process delete host 208.67.220.220 fib 0: not in table'
Jun 24 10:37:15	php-fpm	74632	/rc.resolv_conf_generate: The command '/sbin/route delete -host 208.67.222.222 ' returned exit code '1', the output was 'route: writing to routing socket: No such process delete host 208.67.222.222 fib 0: not in table'
Jun 24 10:37:15	php-fpm	74632	/rc.newwanipv6: rc.newwanipv6: No IPv6 address found for interface WAN [wan].
Jun 24 10:37:15	php-fpm	74632	/rc.newwanipv6: rc.newwanipv6: Info: starting on pppoe1.
Jun 24 10:37:15	xinetd	14152	Reconfigured: new=0 old=1 dropped=0 (services)
Jun 24 10:37:15	xinetd	14152	readjusting service 6969-udp
Jun 24 10:37:15	xinetd	14152	Swapping defaults
Jun 24 10:37:15	xinetd	14152	Starting reconfiguration
Jun 24 10:37:15	php-fpm	65464	/rc.newwanip: IP has changed, killing states on former IP 79.47.194.62.
Jun 24 10:37:15	php-fpm	65464	/rc.newwanip: ROUTING: setting IPv6 default route to 2001:470:1f12:62c::1
Jun 24 10:37:15	kernel		gif0: link state changed to UP
Jun 24 10:37:15	kernel		gif0: link state changed to DOWN
Jun 24 10:37:15	php-fpm	65464	/rc.newwanip: DEBUG: interface: opt1 interfacegw: wan gatewayip:
Jun 24 10:37:15	php-fpm	65464	/rc.newwanip: ROUTING: setting IPv6 default route to 2001:470:1f12:62c::1
Jun 24 10:37:15	kernel		gif0: link state changed to UP
Jun 24 10:37:15	kernel		gif0: link state changed to DOWN
Jun 24 10:37:15	php-fpm	65464	/rc.newwanip: DEBUG: interface: opt1 interfacegw: wan gatewayip:
Jun 24 10:37:15	php-fpm	65464	/rc.newwanip: The command '/sbin/route delete -host 208.67.220.220 ' returned exit code '1', the output was 'route: writing to routing socket: No such process delete host 208.67.220.220 fib 0: not in table'
Jun 24 10:37:15	php-fpm	65464	/rc.newwanip: The command '/sbin/route delete -host 208.67.222.222 ' returned exit code '1', the output was 'route: writing to routing socket: No such process delete host 208.67.222.222 fib 0: not in table'
Jun 24 10:37:15	php-fpm	65464	/rc.newwanip: rc.newwanip: on (IP address: 79.56.147.131) (interface: WAN[wan]) (real interface: pppoe1).
Jun 24 10:37:15	php-fpm	65464	/rc.newwanip: rc.newwanip: Info: starting on pppoe1.
Jun 24 10:37:14	check_reload_status		Rewriting resolv.conf
Jun 24 10:37:14	ppp		[wan] IPV6CP: LayerDown
Jun 24 10:37:14	ppp		[wan] IPV6CP: SendTerminateAck #2
Jun 24 10:37:14	ppp		[wan] IPV6CP: state change Opened --> Stopping
Jun 24 10:37:14	ppp		[wan] IPV6CP: rec'd Terminate Request #164 (Opened)
Jun 24 10:37:14	check_reload_status		rc.newwanipv6 starting pppoe1
Jun 24 10:37:14	ppp		[wan] 76d4:35ff:fe8a:b19c -> 02a0:a50f:fc86:8004
Jun 24 10:37:14	ppp		[wan] IPV6CP: LayerUp
Jun 24 10:37:14	ppp		[wan] IPV6CP: state change Ack-Rcvd --> Opened
Jun 24 10:37:14	ppp		[wan] IPV6CP: SendConfigAck #163
Jun 24 10:37:14	ppp		[wan] IPV6CP: rec'd Configure Request #163 (Ack-Rcvd)
Jun 24 10:37:14	ppp		[wan] IFACE: Rename interface ng0 to pppoe1
Jun 24 10:37:14	ppp		[wan] IFACE: Up event
Jun 24 10:37:14	check_reload_status		rc.newwanip starting pppoe1
Jun 24 10:37:13	ppp		[wan] 79.56.147.131 -> 192.168.100.1
Jun 24 10:37:13	ppp		[wan] IPCP: LayerUp
Jun 24 10:37:13	ppp		[wan] IPCP: state change Ack-Rcvd --> Opened
Jun 24 10:37:13	ppp		[wan] IPADDR 192.168.100.1
Jun 24 10:37:13	ppp		[wan] IPCP: SendConfigAck #109
Jun 24 10:37:13	ppp		[wan] 192.168.100.1 is OK
Jun 24 10:37:13	ppp		[wan] IPADDR 192.168.100.1
Jun 24 10:37:13	ppp		[wan] IPCP: rec'd Configure Request #109 (Ack-Rcvd)
Jun 24 10:37:13	ppp		[wan] IPCP: state change Req-Sent --> Ack-Rcvd
Jun 24 10:37:13	ppp		[wan] IPADDR 79.56.147.131
Jun 24 10:37:13	ppp		[wan] IPCP: rec'd Configure Ack #3 (Req-Sent)
Jun 24 10:37:13	ppp		[wan] IPADDR 79.56.147.131
Jun 24 10:37:13	ppp		[wan] IPCP: SendConfigReq #3
Jun 24 10:37:13	ppp		[wan] 79.56.147.131 is OK
Jun 24 10:37:13	ppp		[wan] IPADDR 79.56.147.131
Jun 24 10:37:13	ppp		[wan] IPCP: rec'd Configure Nak #2 (Req-Sent)
Jun 24 10:37:13	ppp		[wan] IPV6CP: state change Req-Sent --> Ack-Rcvd
Jun 24 10:37:13	ppp		[wan] IPV6CP: rec'd Configure Ack #1 (Req-Sent)
Jun 24 10:37:13	ppp		[wan] IPADDR 0.0.0.0
Jun 24 10:37:13	ppp		[wan] IPCP: SendConfigReq #2
Jun 24 10:37:13	ppp		[wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jun 24 10:37:13	ppp		[wan] IPCP: rec'd Configure Reject #1 (Req-Sent)
Jun 24 10:37:13	ppp		[wan] IPV6CP: SendConfigReq #1
Jun 24 10:37:13	ppp		[wan] IPV6CP: state change Starting --> Req-Sent
Jun 24 10:37:13	ppp		[wan] IPV6CP: Up event
Jun 24 10:37:13	ppp		[wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jun 24 10:37:13	ppp		[wan] IPADDR 0.0.0.0
Jun 24 10:37:13	ppp		[wan] IPCP: SendConfigReq #1
Jun 24 10:37:13	ppp		[wan] IPCP: state change Starting --> Req-Sent
Jun 24 10:37:13	ppp		[wan] IPCP: Up event
Jun 24 10:37:13	ppp		[wan] IPV6CP: LayerStart
Jun 24 10:37:13	ppp		[wan] IPV6CP: state change Initial --> Starting
Jun 24 10:37:13	ppp		[wan] IPV6CP: Open event
Jun 24 10:37:13	ppp		[wan] IPCP: LayerStart
Jun 24 10:37:13	ppp		[wan] IPCP: state change Initial --> Starting
Jun 24 10:37:13	ppp		[wan] IPCP: Open event
Jun 24 10:37:13	ppp		[wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Jun 24 10:37:13	ppp		[wan_link0] Link: Join bundle "wan"
Jun 24 10:37:13	ppp		[wan_link0] Link: Matched action 'bundle "wan" ""'
Jun 24 10:37:13	ppp		[wan_link0] LCP: authorization successful
Jun 24 10:37:13	ppp		[wan_link0] PAP: rec'd ACK #1 len: 5
Jun 24 10:37:13	ppp		[wan_link0] LCP: LayerUp
Jun 24 10:37:13	ppp		[wan_link0] PAP: sending REQUEST #1 len: 24
Jun 24 10:37:13	ppp		[wan_link0] PAP: using authname "aliceadsl"
Jun 24 10:37:13	ppp		[wan_link0] LCP: auth: peer wants PAP, I want nothing
Jun 24 10:37:13	ppp		[wan_link0] LCP: state change Ack-Sent --> Opened
Jun 24 10:37:13	ppp		[wan_link0] MAGICNUM 0xb26eca2e
Jun 24 10:37:13	ppp		[wan_link0] MRU 1492
Jun 24 10:37:13	ppp		[wan_link0] PROTOCOMP
Jun 24 10:37:13	ppp		[wan_link0] LCP: rec'd Configure Ack #1 (Ack-Sent)
Jun 24 10:37:13	ppp		[wan_link0] LCP: state change Req-Sent --> Ack-Sent
Jun 24 10:37:13	ppp		[wan_link0] MAGICNUM 0x5794e7e4
Jun 24 10:37:13	ppp		[wan_link0] AUTHPROTO PAP
Jun 24 10:37:13	ppp		[wan_link0] MRU 1492
Jun 24 10:37:13	ppp		[wan_link0] LCP: SendConfigAck #138
Jun 24 10:37:13	ppp		[wan_link0] MAGICNUM 0x5794e7e4
Jun 24 10:37:13	ppp		[wan_link0] AUTHPROTO PAP
Jun 24 10:37:13	ppp		[wan_link0] MRU 1492
Jun 24 10:37:13	ppp		[wan_link0] LCP: rec'd Configure Request #138 (Req-Sent)
Jun 24 10:37:13	ppp		[wan_link0] MAGICNUM 0xb26eca2e
Jun 24 10:37:13	ppp		[wan_link0] MRU 1492
Jun 24 10:37:13	ppp		[wan_link0] PROTOCOMP
Jun 24 10:37:13	ppp		[wan_link0] LCP: SendConfigReq #1
Jun 24 10:37:13	ppp		[wan_link0] LCP: state change Starting --> Req-Sent
Jun 24 10:37:13	ppp		[wan_link0] LCP: Up event
Jun 24 10:37:13	ppp		[wan_link0] Link: UP event
Jun 24 10:37:13	ppp		[wan_link0] PPPoE: connection successful
Jun 24 10:37:13	ppp		PPPoE: rec'd ACNAME "r-rm900"
Jun 24 10:37:13	ppp		[wan_link0] PPPoE: Connecting to 'TelecomFibra'
Jun 24 10:37:13	ppp		[wan_link0] LCP: LayerStart
Jun 24 10:37:13	ppp		[wan_link0] LCP: state change Initial --> Starting
Jun 24 10:37:13	ppp		[wan_link0] LCP: Open event
Jun 24 10:37:13	kernel		ng0: changing name to 'pppoe1'
Jun 24 10:37:13	ppp		[wan_link0] Link: OPEN event
Jun 24 10:37:13	ppp		[wan] Bundle: Interface ng0 created
Jun 24 10:37:13	ppp		web: web is not running
Jun 24 10:37:13	ppp		process 65266 started, version 5.8 (root@pfSense_v2_3_1_amd64-pfSense_v2_3_1-job-13 19:20 16-May-2016)
Jun 24 10:37:13	ppp		Multi-link PPP daemon for FreeBSD
Jun 24 10:37:03	syslogd		kernel boot file is /boot/kernel/kernel

      Thanks in advance,

      Marlenio

      1 Reply Last reply Reply Quote 0
      • C
        cmb
        last edited by

        Thanks, that narrows it down further. get_interface_gateway is returning null in that case. Which likely means that interface's router file is empty at the time. /tmp/pppoe1_router in your case.

        What contents does /tmp/pppoe1_router have after doing that?

        Appreciate your help tracking this down.

        1 Reply Last reply Reply Quote 0
        • M
          Marlenio
          last edited by

          Hi cmb,

          @cmb:

          Thanks, that narrows it down further. get_interface_gateway is returning null in that case. Which likely means that interface's router file is empty at the time. /tmp/pppoe1_router in your case.

          What contents does /tmp/pppoe1_router have after doing that?

          Appreciate your help tracking this down.

          It seems file doesn't exist in both code (reverted 2.2.6 and 2.3.x). The image show /tmp folder with 2.3.1_5 stock code.

          pppoe1_router.png
          pppoe1_router.png_thumb

          Marlenio

          1 Reply Last reply Reply Quote 0
          • C
            cmb
            last edited by

            @Marlenio:

            It seems file doesn't exist in both code (reverted 2.2.6 and 2.3.x). The image show /tmp folder with 2.3.1_5 stock code.

            Ok that's why, now just a question of why that's missing. What is your IPv6 configuration on that interface? Seems like it ends up with pppoe1_routerv6 but not the v4.

            1 Reply Last reply Reply Quote 0
            • M
              Marlenio
              last edited by

              @cmb:

              Ok that's why, now just a question of why that's missing. What is your IPv6 configuration on that interface? Seems like it ends up with pppoe1_routerv6 but not the v4.

              I have a Hurricane Electric /64 on tunnelbroker.net (see attached image).  Yes, there's pppoe_routerv6 but ipv4 is missing.

              Thanks in advance,

              –
              Marlenio

              HE1.png
              HE1.png_thumb
              HE2.png
              HE2.png_thumb
              HE3.png
              HE3.png_thumb

              Marlenio

              1 Reply Last reply Reply Quote 0
              • C
                cmb
                last edited by

                So that pppoe1_routerv6 file contains your HE gateway IP?

                1 Reply Last reply Reply Quote 0
                • M
                  Marlenio
                  last edited by

                  @cmb:

                  So that pppoe1_routerv6 file contains your HE gateway IP?

                  No, the one in pppoe1_routerv6 seems to be a link local address, like the ip in /tmp/pppoe1_ipv6 (fe80::76d4:35ff:fe8a:b19c)

                  IPv6_GW.png
                  IPv6_GW.png_thumb
                  IPv6_GW2.png
                  IPv6_GW2.png_thumb

                  Marlenio

                  1 Reply Last reply Reply Quote 0
                  • C
                    cmb
                    last edited by

                    Odd, it's like ppp-linkup is somehow not getting called or getting called missing some of its arguments.

                    Last (I hope) thing to try to get to the bottom of this. In /usr/local/sbin/ppp-linkup under this line:

                    DNS2_RAW="${7}"

                    Add this line:

                    logger "ppp-linkup IF: $IF | PROTOCOL: $PROTOCOL | LOCAL_IP: $LOCAL_IP | REMOTE_IP: $REMOTE_IP | AUTH_NAME: $AUTH_NAME | DNS1_RAW: $DNS1_RAW | DNS2_RAW: $DNS2_RAW"

                    and replicate again. Then post the system log line that contains something like:

                    root: ppp-linkup IF: pppoe1 | PROTOCOL: …

                    1 Reply Last reply Reply Quote 0
                    • M
                      Marlenio
                      last edited by

                      Hi cmb,

                      @cmb:

                      Odd, it's like ppp-linkup is somehow not getting called or getting called missing some of its arguments.

                      Last (I hope) thing to try to get to the bottom of this. In /usr/local/sbin/ppp-linkup under this line:

                      Thank you, in late afternoon i'll made the change and then post the log here.  :)

                      Marlenio

                      1 Reply Last reply Reply Quote 0
                      • M
                        Marlenio
                        last edited by

                        Hi cmb,
                        here is the system log with stock source:

                        
Jun 30 18:00:27	ftp-proxy	64428	listening on 127.0.0.1 port 8021
Jun 30 18:00:27	check_reload_status		Syncing firewall
Jun 30 18:00:27	php-fpm	42987	[pfBlockerNG] Starting cron process.
Jun 30 18:00:27	ftp-proxy	60589	listening on 127.0.0.1 port 8021
Jun 30 18:00:27	check_reload_status		Reloading filter
Jun 30 18:00:27	php-fpm	42987	/rc.start_packages: Restarting/Starting all packages.
Jun 30 18:00:26	xinetd	13847	Reconfigured: new=0 old=1 dropped=0 (services)
Jun 30 18:00:26	xinetd	13847	readjusting service 6969-udp
Jun 30 18:00:26	xinetd	13847	Swapping defaults
Jun 30 18:00:26	xinetd	13847	Starting reconfiguration
Jun 30 18:00:25	xinetd	13847	Reconfigured: new=0 old=1 dropped=0 (services)
Jun 30 18:00:25	xinetd	13847	readjusting service 6969-udp
Jun 30 18:00:25	xinetd	13847	Swapping defaults
Jun 30 18:00:25	xinetd	13847	Starting reconfiguration
Jun 30 18:00:23	xinetd	13847	Reconfigured: new=0 old=1 dropped=0 (services)
Jun 30 18:00:23	xinetd	13847	readjusting service 6969-udp
Jun 30 18:00:23	xinetd	13847	Swapping defaults
Jun 30 18:00:23	xinetd	13847	Starting reconfiguration
Jun 30 18:00:23	check_reload_status		Reloading filter
Jun 30 18:00:23	php-fpm	42987	/rc.newipsecdns: IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
Jun 30 18:00:08	check_reload_status		Reloading filter
Jun 30 18:00:08	php-fpm	42987	/rc.newipsecdns: IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
Jun 30 17:59:52	php-fpm	42987	/rc.dyndns.update: Curl error occurred: Could not resolve host: ipv4.tunnelbroker.net
Jun 30 17:59:42	php-fpm	42987	/rc.dyndns.update: Curl error occurred: Could not resolve host: freedns.afraid.org
Jun 30 17:59:42	php-fpm	42987	/rc.dyndns.update: Dynamic DNS freedns (casalener.mooo.com): _checkStatus() starting.
Jun 30 17:59:34	php-fpm	42987	/rc.dyndns.update: Dynamic DNS freedns (casalener.mooo.com): _update() starting.
Jun 30 17:59:34	php-fpm	42987	/rc.dyndns.update: DynDns (casalener.mooo.com): Dynamic Dns: cacheIP != wan_ip. Updating. Cached IP: 82.57.156.105 WAN IP: 95.247.53.52
Jun 30 17:59:34	php-fpm	42987	/rc.dyndns.update: Dynamic Dns (casalener.mooo.com): Current WAN IP: 95.247.53.52 Cached IP: 82.57.156.105
Jun 30 17:59:34	php-fpm	42987	/rc.dyndns.update: Dynamic DNS freedns (casalener.mooo.com): 95.247.53.52 extracted from local system.
Jun 30 17:59:34	php-fpm	42987	/rc.dyndns.update: Dynamic DNS (casalener.mooo.com): running get_failover_interface for wan. found pppoe1
Jun 30 17:59:34	php-fpm	42987	/rc.dyndns.update: Dynamic DNS freedns (casalener.mooo.com): 95.247.53.52 extracted from local system.
Jun 30 17:59:34	php-fpm	42987	/rc.dyndns.update: Dynamic DNS: updatedns() starting
Jun 30 17:59:33	php-fpm	42987	/rc.dyndns.update: Curl error occurred: Could not resolve host: dynupdate.no-ip.com
Jun 30 17:59:24	php-fpm	42987	/rc.resolv_conf_generate: The command '/sbin/route delete -host 208.67.220.220 ' returned exit code '1', the output was 'route: writing to routing socket: No such process delete host 208.67.220.220 fib 0: not in table'
Jun 30 17:59:24	php-fpm	42987	/rc.resolv_conf_generate: The command '/sbin/route delete -host 208.67.222.222 ' returned exit code '1', the output was 'route: writing to routing socket: No such process delete host 208.67.222.222 fib 0: not in table'
Jun 30 17:59:24	php-fpm	42987	/rc.newwanipv6: rc.newwanipv6: No IPv6 address found for interface WAN [wan].
Jun 30 17:59:24	php-fpm	42987	/rc.newwanipv6: rc.newwanipv6: Info: starting on pppoe1.
Jun 30 17:59:24	check_reload_status		Starting packages
Jun 30 17:59:24	php-fpm	42987	/rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 82.57.156.105 -> 95.247.53.52 - Restarting packages.
Jun 30 17:59:22	php-fpm	42987	/rc.newwanip: Creating rrd update script
Jun 30 17:59:22	php-fpm	42987	/rc.newwanip: Resyncing OpenVPN instances for interface WAN.
Jun 30 17:59:22	check_reload_status		Reloading filter
Jun 30 17:59:22	php-fpm	42987	/rc.newwanip: Forcefully reloading IPsec
Jun 30 17:59:21	php-fpm	42987	/rc.newwanip: Curl error occurred: Could not resolve host: ipv4.tunnelbroker.net
Jun 30 17:59:11	php-fpm	42987	/rc.newwanip: Curl error occurred: Could not resolve host: freedns.afraid.org
Jun 30 17:59:11	php-fpm	42987	/rc.newwanip: Dynamic DNS freedns (casalener.mooo.com): _checkStatus() starting.
Jun 30 17:59:03	php-cgi		servicewatchdog_cron.php: The command '/usr/local/sbin/unbound -c /var/unbound/unbound.conf' returned exit code '1', the output was '[1467302343] unbound[3597:0] error: bind: address already in use [1467302343] unbound[3597:0] fatal error: could not open ports'
Jun 30 17:59:02	php-fpm	42987	/rc.newwanip: Dynamic DNS freedns (casalener.mooo.com): _update() starting.
Jun 30 17:59:02	php-fpm	42987	/rc.newwanip: DynDns (casalener.mooo.com): Dynamic Dns: cacheIP != wan_ip. Updating. Cached IP: 82.57.156.105 WAN IP: 95.247.53.52
Jun 30 17:59:02	php-fpm	42987	/rc.newwanip: Dynamic Dns (casalener.mooo.com): Current WAN IP: 95.247.53.52 Cached IP: 82.57.156.105
Jun 30 17:59:02	php-fpm	42987	/rc.newwanip: Dynamic DNS freedns (casalener.mooo.com): 95.247.53.52 extracted from local system.
Jun 30 17:59:02	php-fpm	42987	/rc.newwanip: Dynamic DNS (casalener.mooo.com): running get_failover_interface for wan. found pppoe1
Jun 30 17:59:02	php-fpm	42987	/rc.newwanip: Dynamic DNS freedns (casalener.mooo.com): 95.247.53.52 extracted from local system.
Jun 30 17:59:02	php-fpm	42987	/rc.newwanip: Dynamic DNS: updatedns() starting
Jun 30 17:59:01	php-fpm	42987	/rc.newwanip: Curl error occurred: Could not resolve host: dynupdate.no-ip.com
Jun 30 17:58:04	php-cgi		servicewatchdog_cron.php: Could not send the message to mario.lener@gmail.com -- Error: could not resolve the host domain "smtp.gmail.com"
Jun 30 17:58:00	php-cgi		servicewatchdog_cron.php: Service Watchdog detected service unbound stopped. Restarting unbound (Unbound DNS Resolver)
Jun 30 17:57:55	check_reload_status		Reloading filter
Jun 30 17:57:55	check_reload_status		Restarting OpenVPN tunnels/interfaces
Jun 30 17:57:55	check_reload_status		Reloading filter
Jun 30 17:57:55	check_reload_status		Restarting ipsec tunnels
Jun 30 17:57:55	check_reload_status		Restarting OpenVPN tunnels/interfaces
Jun 30 17:57:55	check_reload_status		updating dyndns HE_IPV6_TUNNELV6
Jun 30 17:57:55	check_reload_status		Restarting ipsec tunnels
Jun 30 17:57:55	check_reload_status		updating dyndns WAN_PPPOE
Jun 30 17:57:52	php-fpm	42987	/rc.newwanip: Removing static route for monitor 2001:4860:4860::8888 and adding a new route through 2001:470:1f12:62c::1
Jun 30 17:57:51	xinetd	13847	Reconfigured: new=0 old=1 dropped=0 (services)
Jun 30 17:57:51	xinetd	13847	readjusting service 6969-udp
Jun 30 17:57:51	xinetd	13847	Swapping defaults
Jun 30 17:57:51	xinetd	13847	Starting reconfiguration
Jun 30 17:57:50	php-fpm	42987	/rc.newwanip: IP has changed, killing states on former IP 82.57.156.105.
Jun 30 17:57:50	php-fpm	42987	/rc.newwanip: ROUTING: setting IPv6 default route to 2001:470:1f12:62c::1
Jun 30 17:57:50	kernel		gif0: link state changed to UP
Jun 30 17:57:50	kernel		gif0: link state changed to DOWN
Jun 30 17:57:50	kernel		gif0: link state changed to UP
Jun 30 17:57:50	kernel		gif0: link state changed to DOWN
Jun 30 17:57:50	php-fpm	42987	/rc.newwanip: ROUTING: setting IPv6 default route to 2001:470:1f12:62c::1
Jun 30 17:57:50	php-fpm	42987	/rc.newwanip: The command '/sbin/route delete -host 208.67.220.220 ' returned exit code '1', the output was 'route: writing to routing socket: No such process delete host 208.67.220.220 fib 0: not in table'
Jun 30 17:57:50	php-fpm	42987	/rc.newwanip: The command '/sbin/route delete -host 208.67.222.222 ' returned exit code '1', the output was 'route: writing to routing socket: No such process delete host 208.67.222.222 fib 0: not in table'
Jun 30 17:57:50	php-fpm	42987	/rc.newwanip: rc.newwanip: on (IP address: 95.247.53.52) (interface: WAN[wan]) (real interface: pppoe1).
Jun 30 17:57:50	php-fpm	42987	/rc.newwanip: rc.newwanip: Info: starting on pppoe1.
Jun 30 17:57:49	xinetd	13847	Reconfigured: new=0 old=1 dropped=0 (services)
Jun 30 17:57:49	xinetd	13847	readjusting service 6969-udp
Jun 30 17:57:49	xinetd	13847	Swapping defaults
Jun 30 17:57:49	xinetd	13847	Starting reconfiguration
Jun 30 17:57:48	xinetd	13847	Reconfigured: new=0 old=1 dropped=0 (services)
Jun 30 17:57:48	xinetd	13847	readjusting service 6969-udp
Jun 30 17:57:48	xinetd	13847	Swapping defaults
Jun 30 17:57:48	xinetd	13847	Starting reconfiguration
Jun 30 17:57:48	kernel		gif0: link state changed to UP
Jun 30 17:57:48	kernel		gif0: link state changed to DOWN
Jun 30 17:57:48	php-fpm	42987	/status_interfaces.php: ROUTING: setting IPv6 default route to 2001:470:1f12:62c::1
Jun 30 17:57:45	ppp		[wan] IPV6CP: LayerFinish
Jun 30 17:57:45	ppp		[wan] IPV6CP: state change Stopping --> Stopped
Jun 30 17:57:43	check_reload_status		Rewriting resolv.conf
Jun 30 17:57:42	ppp		[wan] IPV6CP: LayerDown
Jun 30 17:57:42	ppp		[wan] IPV6CP: SendTerminateAck #10
Jun 30 17:57:42	ppp		[wan] IPV6CP: state change Opened --> Stopping
Jun 30 17:57:42	ppp		[wan] IPV6CP: rec'd Terminate Request #83 (Opened)
Jun 30 17:57:42	check_reload_status		rc.newwanipv6 starting pppoe1
Jun 30 17:57:42	root		ppp-linkup IF: pppoe1 | PROTOCOL: inet6 | LOCAL_IP: fe80::76d4:35ff:fe8a:b19c%pppoe1 | REMOTE_IP: fe80::2a0:a50f:fc86:8004%pppoe1 | AUTH_NAME: - | DNS1_RAW: 00:00:00:00:00:00 | DNS2_RAW: -
Jun 30 17:57:42	ppp		[wan] 76d4:35ff:fe8a:b19c -> 02a0:a50f:fc86:8004
Jun 30 17:57:42	ppp		[wan] IPV6CP: LayerUp
Jun 30 17:57:42	ppp		[wan] IPV6CP: state change Ack-Rcvd --> Opened
Jun 30 17:57:42	ppp		[wan] IPV6CP: SendConfigAck #82
Jun 30 17:57:42	ppp		[wan] IPV6CP: rec'd Configure Request #82 (Ack-Rcvd)
Jun 30 17:57:42	ppp		[wan] IPV6CP: state change Req-Sent --> Ack-Rcvd
Jun 30 17:57:42	ppp		[wan] IPV6CP: rec'd Configure Ack #9 (Req-Sent)
Jun 30 17:57:42	ppp		[wan] IPV6CP: SendConfigReq #9
Jun 30 17:57:40	ppp		[wan] IPV6CP: SendTerminateAck #8
Jun 30 17:57:40	ppp		[wan] IPV6CP: state change Ack-Sent --> Req-Sent
Jun 30 17:57:40	ppp		[wan] IPV6CP: rec'd Terminate Request #168 (Ack-Sent)
Jun 30 17:57:40	ppp		[wan] IPV6CP: state change Req-Sent --> Ack-Sent
Jun 30 17:57:40	ppp		[wan] IPV6CP: SendConfigAck #167
Jun 30 17:57:40	ppp		[wan] IPV6CP: rec'd Configure Request #167 (Req-Sent)
Jun 30 17:57:40	ppp		[wan] IPV6CP: SendTerminateAck #7
Jun 30 17:57:40	ppp		[wan] IPV6CP: rec'd Terminate Request #166 (Req-Sent)
Jun 30 17:57:40	ppp		[wan] IPV6CP: SendTerminateAck #6
Jun 30 17:57:40	ppp		[wan] IPV6CP: state change Ack-Rcvd --> Req-Sent
Jun 30 17:57:40	ppp		[wan] IPV6CP: rec'd Terminate Request #165 (Ack-Rcvd)
Jun 30 17:57:40	ppp		[wan] IPV6CP: state change Req-Sent --> Ack-Rcvd
Jun 30 17:57:40	ppp		[wan] IPV6CP: rec'd Configure Ack #5 (Req-Sent)
Jun 30 17:57:40	ppp		[wan] IPV6CP: SendConfigReq #5
Jun 30 17:57:38	ppp		[wan] IPV6CP: SendTerminateAck #4
Jun 30 17:57:38	ppp		[wan] IPV6CP: state change Ack-Sent --> Req-Sent
Jun 30 17:57:38	ppp		[wan] IPV6CP: rec'd Terminate Request #19 (Ack-Sent)
Jun 30 17:57:38	ppp		[wan] IPV6CP: state change Req-Sent --> Ack-Sent
Jun 30 17:57:38	ppp		[wan] IPV6CP: SendConfigAck #18
Jun 30 17:57:38	ppp		[wan] IPV6CP: rec'd Configure Request #18 (Req-Sent)
Jun 30 17:57:38	ppp		[wan] IFACE: Rename interface ng0 to pppoe1
Jun 30 17:57:38	ppp		[wan] IFACE: Up event
Jun 30 17:57:38	check_reload_status		rc.newwanip starting pppoe1
Jun 30 17:57:38	root		ppp-linkup IF: pppoe1 | PROTOCOL: inet | LOCAL_IP: 95.247.53.52/32 | REMOTE_IP: 192.168.100.1 | AUTH_NAME: - | DNS1_RAW: | DNS2_RAW:
Jun 30 17:57:38	ppp		[wan] 95.247.53.52 -> 192.168.100.1
Jun 30 17:57:38	ppp		[wan] IPCP: LayerUp
Jun 30 17:57:38	ppp		[wan] IPCP: state change Ack-Rcvd --> Opened
Jun 30 17:57:38	ppp		[wan] IPADDR 192.168.100.1
Jun 30 17:57:38	ppp		[wan] IPCP: SendConfigAck #175
Jun 30 17:57:38	ppp		[wan] 192.168.100.1 is OK
Jun 30 17:57:38	ppp		[wan] IPADDR 192.168.100.1
Jun 30 17:57:38	ppp		[wan] IPCP: rec'd Configure Request #175 (Ack-Rcvd)
Jun 30 17:57:38	ppp		[wan] IPV6CP: SendTerminateAck #3
Jun 30 17:57:38	ppp		[wan] IPV6CP: rec'd Terminate Request #17 (Req-Sent)
Jun 30 17:57:38	ppp		[wan] IPV6CP: SendTerminateAck #2
Jun 30 17:57:38	ppp		[wan] IPV6CP: state change Ack-Rcvd --> Req-Sent
Jun 30 17:57:38	ppp		[wan] IPV6CP: rec'd Terminate Request #16 (Ack-Rcvd)
Jun 30 17:57:38	ppp		[wan] IPCP: state change Req-Sent --> Ack-Rcvd
Jun 30 17:57:38	ppp		[wan] IPADDR 95.247.53.52
Jun 30 17:57:38	ppp		[wan] IPCP: rec'd Configure Ack #3 (Req-Sent)
Jun 30 17:57:38	ppp		[wan] IPADDR 95.247.53.52
Jun 30 17:57:38	ppp		[wan] IPCP: SendConfigReq #3
Jun 30 17:57:38	ppp		[wan] 95.247.53.52 is OK
Jun 30 17:57:38	ppp		[wan] IPADDR 95.247.53.52
Jun 30 17:57:38	ppp		[wan] IPCP: rec'd Configure Nak #2 (Req-Sent)
Jun 30 17:57:38	ppp		[wan] IPV6CP: state change Req-Sent --> Ack-Rcvd
Jun 30 17:57:38	ppp		[wan] IPV6CP: rec'd Configure Ack #1 (Req-Sent)
Jun 30 17:57:38	ppp		[wan] IPADDR 0.0.0.0
Jun 30 17:57:38	ppp		[wan] IPCP: SendConfigReq #2
Jun 30 17:57:38	ppp		[wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jun 30 17:57:38	ppp		[wan] IPCP: rec'd Configure Reject #1 (Req-Sent)
Jun 30 17:57:38	ppp		[wan] IPV6CP: SendConfigReq #1
Jun 30 17:57:38	ppp		[wan] IPV6CP: state change Starting --> Req-Sent
Jun 30 17:57:38	ppp		[wan] IPV6CP: Up event
Jun 30 17:57:38	ppp		[wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
Jun 30 17:57:38	ppp		[wan] IPADDR 0.0.0.0
Jun 30 17:57:38	ppp		[wan] IPCP: SendConfigReq #1
Jun 30 17:57:38	ppp		[wan] IPCP: state change Starting --> Req-Sent
Jun 30 17:57:38	ppp		[wan] IPCP: Up event
Jun 30 17:57:38	ppp		[wan] IPV6CP: LayerStart
Jun 30 17:57:38	ppp		[wan] IPV6CP: state change Initial --> Starting
Jun 30 17:57:38	ppp		[wan] IPV6CP: Open event
Jun 30 17:57:38	ppp		[wan] IPCP: LayerStart
Jun 30 17:57:38	ppp		[wan] IPCP: state change Initial --> Starting
Jun 30 17:57:38	ppp		[wan] IPCP: Open event
Jun 30 17:57:38	ppp		[wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps
Jun 30 17:57:38	ppp		[wan_link0] Link: Join bundle "wan"
Jun 30 17:57:38	ppp		[wan_link0] Link: Matched action 'bundle "wan" ""'
Jun 30 17:57:38	ppp		[wan_link0] LCP: authorization successful
Jun 30 17:57:38	ppp		[wan_link0] PAP: rec'd ACK #1 len: 5
Jun 30 17:57:38	ppp		[wan_link0] LCP: LayerUp
Jun 30 17:57:38	ppp		[wan_link0] PAP: sending REQUEST #1 len: 24
Jun 30 17:57:38	ppp		[wan_link0] PAP: using authname "aliceadsl"
Jun 30 17:57:38	ppp		[wan_link0] LCP: auth: peer wants PAP, I want nothing
Jun 30 17:57:38	ppp		[wan_link0] LCP: state change Ack-Sent --> Opened
Jun 30 17:57:38	ppp		[wan_link0] MAGICNUM 0x959498d9
Jun 30 17:57:38	ppp		[wan_link0] MRU 1492
Jun 30 17:57:38	ppp		[wan_link0] PROTOCOMP
Jun 30 17:57:38	ppp		[wan_link0] LCP: rec'd Configure Ack #1 (Ack-Sent)
Jun 30 17:57:38	ppp		[wan_link0] LCP: state change Req-Sent --> Ack-Sent
Jun 30 17:57:38	ppp		[wan_link0] MAGICNUM 0x484e41c9
Jun 30 17:57:38	ppp		[wan_link0] AUTHPROTO PAP
Jun 30 17:57:38	ppp		[wan_link0] MRU 1492
Jun 30 17:57:38	ppp		[wan_link0] LCP: SendConfigAck #51
Jun 30 17:57:38	ppp		[wan_link0] MAGICNUM 0x484e41c9
Jun 30 17:57:38	ppp		[wan_link0] AUTHPROTO PAP
Jun 30 17:57:38	ppp		[wan_link0] MRU 1492
Jun 30 17:57:38	ppp		[wan_link0] LCP: rec'd Configure Request #51 (Req-Sent)
Jun 30 17:57:38	ppp		[wan_link0] MAGICNUM 0x959498d9
Jun 30 17:57:38	ppp		[wan_link0] MRU 1492
Jun 30 17:57:38	ppp		[wan_link0] PROTOCOMP
Jun 30 17:57:38	ppp		[wan_link0] LCP: SendConfigReq #1
Jun 30 17:57:38	ppp		[wan_link0] LCP: state change Starting --> Req-Sent
Jun 30 17:57:38	ppp		[wan_link0] LCP: Up event
Jun 30 17:57:38	ppp		[wan_link0] Link: UP event
Jun 30 17:57:38	ppp		[wan_link0] PPPoE: connection successful
Jun 30 17:57:38	ppp		PPPoE: rec'd ACNAME "r-rm900"
Jun 30 17:57:38	ppp		[wan_link0] PPPoE: Connecting to 'TelecomFibra'
Jun 30 17:57:38	ppp		[wan_link0] LCP: LayerStart
Jun 30 17:57:38	ppp		[wan_link0] LCP: state change Initial --> Starting
Jun 30 17:57:38	ppp		[wan_link0] LCP: Open event
Jun 30 17:57:38	kernel		ng0: changing name to 'pppoe1'
Jun 30 17:57:38	ppp		[wan_link0] Link: OPEN event
Jun 30 17:57:38	ppp		[wan] Bundle: Interface ng0 created
Jun 30 17:57:38	ppp		web: web is not running
Jun 30 17:57:38	ppp		process 38583 started, version 5.8 (root@pfSense_v2_3_1_amd64-pfSense_v2_3_1-job-13 19:20 16-May-2016)
Jun 30 17:57:38	ppp		Multi-link PPP daemon for FreeBSD
Jun 30 17:57:37	xinetd	13847	Reconfigured: new=0 old=1 dropped=0 (services)
Jun 30 17:57:37	xinetd	13847	readjusting service 6969-udp
Jun 30 17:57:37	xinetd	13847	Swapping defaults
Jun 30 17:57:37	xinetd	13847	Starting reconfiguration
Jun 30 17:57:36	php-fpm	42987	/rc.newipsecdns: IPsec ERROR: Could not find phase 1 source for connection Soflab MI (FW-MI01 Endpoint). Omitting from configuration file.
Jun 30 17:57:36	php-fpm	42987	/rc.newipsecdns: IPsec ERROR: Could not find phase 1 source for connection Soflab RM (FW-LW01 Endpoint). Omitting from configuration file.
Jun 30 17:57:36	check_reload_status		Reloading filter
Jun 30 17:57:36	php-fpm	42987	/rc.newipsecdns: IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
Jun 30 17:57:20	xinetd	13847	Reconfigured: new=0 old=1 dropped=0 (services)
Jun 30 17:57:20	xinetd	13847	readjusting service 6969-udp
Jun 30 17:57:20	xinetd	13847	Swapping defaults
Jun 30 17:57:20	xinetd	13847	Starting reconfiguration
Jun 30 17:57:20	php-fpm	42987	/rc.newipsecdns: IPsec ERROR: Could not find phase 1 source for connection Soflab MI (FW-MI01 Endpoint). Omitting from configuration file.
Jun 30 17:57:20	php-fpm	42987	/rc.newipsecdns: IPsec ERROR: Could not find phase 1 source for connection Soflab RM (FW-LW01 Endpoint). Omitting from configuration file.
Jun 30 17:57:20	check_reload_status		Reloading filter
Jun 30 17:57:20	php-fpm	42987	/rc.newipsecdns: IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing.
Jun 30 17:57:04	php-fpm	42987	/rc.dyndns.update: Dynamic DNS (310435) There was an error trying to determine the public IP for interface - wan (pppoe1 ).
Jun 30 17:57:03	php-fpm	42987	/rc.dyndns.update: Dynamic DNS (casalener.mooo.com) There was an error trying to determine the public IP for interface - wan (pppoe1 ).
Jun 30 17:57:03	php-fpm	42987	/rc.dyndns.update: Dynamic DNS (casalener.mooo.com): running get_failover_interface for wan. found pppoe1
Jun 30 17:57:03	php-fpm	42987	/rc.dyndns.update: Dynamic DNS: updatedns() starting
Jun 30 17:57:02	php-fpm	42987	/rc.dyndns.update: Dynamic DNS (casalener.no-ip.info) There was an error trying to determine the public IP for interface - wan (pppoe1 ).
Jun 30 17:57:01	check_reload_status		Reloading filter
Jun 30 17:57:01	check_reload_status		Restarting OpenVPN tunnels/interfaces
Jun 30 17:57:01	check_reload_status		Restarting ipsec tunnels
Jun 30 17:57:01	check_reload_status		updating dyndns HE_IPV6_TUNNELV6
Jun 30 17:57:00	check_reload_status		Reloading filter
Jun 30 17:57:00	check_reload_status		Restarting OpenVPN tunnels/interfaces
Jun 30 17:57:00	check_reload_status		Restarting ipsec tunnels
Jun 30 17:57:00	check_reload_status		updating dyndns WAN_PPPOE
Jun 30 17:57:00	syslogd		kernel boot file is /boot/kernel/kernel

                        Thanks in advance,

                        Marlenio

                        1 Reply Last reply Reply Quote 0
                        • T
                          Taras_
                          last edited by

                          I have similar problem on one pfSense box after upgrade from 2.2 to 2.3, but my WAN interface is L2TP, not PPPoE.

                          • No default gateway after reboot;
                          • /tmp/l2tp1_defaultgw is empty after reboot;
                          • Edit+save of WAN interface or WAN gateway restores default route.
                          1 Reply Last reply Reply Quote 0
                          • M
                            Marlenio
                            last edited by

                            @Taras:

                            I have similar problem on one pfSense box after upgrade from 2.2 to 2.3, but my WAN interface is L2TP, not PPPoE.

                            • No default gateway after reboot;
                            • /tmp/l2tp1_defaultgw is empty after reboot;
                            • Edit+save of WAN interface or WAN gateway restores default route.

                            Have you try the mod to the code i post?

                            Marlenio

                            1 Reply Last reply Reply Quote 0
                            • C
                              cmb
                              last edited by

                              Thanks for the additional details Marlenio. Not immediately clear what's going on there, and we're about to release 2.3.2. In the interest of fixing this more common issue rather than the less common issue removing "set iface route default" fixed, I brought back 2.2.6 and prior behavior here for 2.3.2.

                              1 Reply Last reply Reply Quote 0
                              • M
                                Marlenio
                                last edited by

                                Thank you Chris,
                                tomorrow i install latest 2.3.2 build with fix.  :)

                                EDIT: test with 2.3.2 snapshot 20160715.0559. Works. :)

                                Marlenio

                                1 Reply Last reply Reply Quote 0
                                • First post
                                  Last post
                                Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.