[solved] PPPoE IA-PD woes



  • Hi all!

    First of all I have perfectly fine working IPv6, here is my config:

    DHCPv6 IA-PD
    I get /56 prefix
    I get /64 WAN connecting segment
    Created /64`s out of that /56
    See attached images for detailed config (dhcpv6_1 and dhcpv6_2)

    Now to the problem…
    Everything works just fine after reboot or pppoe disconnect and then reconnect....

    BUT when I:
    a) unplug modem from ISP and plug it in
    b) Reboot or restart ISP modem
    c) detach and re-attach UTP cable to PPPoE iface (quickly or for a longer time it doesn`t matter)

    I loose IPv6 connectivity completley on my hosts which are on those /64 networks derived from delegated /56.
    Gateway monitoring shows IPv6 as pending and no monitor IP is specified, see attached image (gateway_status).

    If I then disconnect PPPoE and reconnect all comes back online like it should.

    DHCPv6C SUCCESFULL LOG:

    
    Mar 8 11:13:50 	dhcp6c 	58179 	got an expected reply, sleeping.
    Mar 8 11:13:50 	dhcp6c 	58179 	removing server (ID: 00:03:00:01:00:c1:64:d8:3f:00)
    Mar 8 11:13:50 	dhcp6c 	58179 	removing an event on pppoe0, state=REQUEST
    Mar 8 11:13:50 	dhcp6c 	58179 	script "/var/etc/dhcp6c_opt2_script.sh" terminated
    Mar 8 11:13:50 	dhcp6c 	58179 	executes /var/etc/dhcp6c_opt2_script.sh
    Mar 8 11:13:50 	dhcp6c 	58179 	create a prefix 2001:xxxx:xxx:xxx::/56 pltime=140733193647232, vltime=604800
    Mar 8 11:13:50 	dhcp6c 	58179 	make an IA: PD-0
    Mar 8 11:13:50 	dhcp6c 	58179 	Domain search list[0] domain.net.
    Mar 8 11:13:50 	dhcp6c 	58179 	nameserver[1] 2001:xxxx:xxxx:x::10
    Mar 8 11:13:50 	dhcp6c 	58179 	nameserver[0] 2001:xxxx:xxxx:x::12
    Mar 8 11:13:50 	dhcp6c 	58179 	dhcp6c Received REQUEST
    Mar 8 11:13:50 	dhcp6c 	58179 	get DHCP option domain search list, len 10
    Mar 8 11:13:50 	dhcp6c 	58179 	get DHCP option DNS, len 32
    Mar 8 11:13:50 	dhcp6c 	58179 	IA_PD prefix: 2001:xxxx:xxx:xxx::/56 pltime=259200 vltime=604800
    Mar 8 11:13:50 	dhcp6c 	58179 	get DHCP option IA_PD prefix, len 25
    Mar 8 11:13:50 	dhcp6c 	58179 	IA_PD: ID=0, T1=129600, T2=207360
    Mar 8 11:13:50 	dhcp6c 	58179 	get DHCP option IA_PD, len 41
    Mar 8 11:13:50 	dhcp6c 	58179 	DUID: DUID HERE
    Mar 8 11:13:50 	dhcp6c 	58179 	get DHCP option client ID, len 14
    Mar 8 11:13:50 	dhcp6c 	58179 	DUID: DUID HERE
    Mar 8 11:13:50 	dhcp6c 	58179 	get DHCP option server ID, len 10
    Mar 8 11:13:50 	dhcp6c 	58179 	receive reply from fe80::2c1:aaaa:aaaa:aaaa%pppoe0 on pppoe0
    Mar 8 11:13:50 	dhcp6c 	58179 	reset a timer on pppoe0, state=REQUEST, timeo=0, retrans=909
    Mar 8 11:13:50 	dhcp6c 	58179 	send request to ff02::1:2%pppoe0
    Mar 8 11:13:50 	dhcp6c 	58179 	set IA_PD
    Mar 8 11:13:50 	dhcp6c 	58179 	set IA_PD prefix
    Mar 8 11:13:50 	dhcp6c 	58179 	set elapsed time (len 2)
    Mar 8 11:13:50 	dhcp6c 	58179 	set server ID (len 10)
    Mar 8 11:13:50 	dhcp6c 	58179 	set client ID (len 14)
    Mar 8 11:13:50 	dhcp6c 	58179 	a new XID (73f3b0) is generated
    Mar 8 11:13:50 	dhcp6c 	58179 	Sending Request
    Mar 8 11:13:50 	dhcp6c 	58179 	picked a server (ID: 00:03:00:01:00:c1:64:d8:3f:00)
    Mar 8 11:13:49 	dhcp6c 	58179 	reset timer for pppoe0 to 0.996924
    Mar 8 11:13:49 	dhcp6c 	58179 	server ID: 00:03:00:01:00:c1:64:d8:3f:00, pref=-1
    Mar 8 11:13:49 	dhcp6c 	58179 	get DHCP option domain search list, len 10
    Mar 8 11:13:49 	dhcp6c 	58179 	get DHCP option DNS, len 32
    Mar 8 11:13:49 	dhcp6c 	58179 	IA_PD prefix: 2001:xxxx:xxx:xxx::/56 pltime=259200 vltime=604800
    Mar 8 11:13:49 	dhcp6c 	58179 	get DHCP option IA_PD prefix, len 25
    Mar 8 11:13:49 	dhcp6c 	58179 	IA_PD: ID=0, T1=129600, T2=207360
    Mar 8 11:13:49 	dhcp6c 	58179 	get DHCP option IA_PD, len 41
    Mar 8 11:13:49 	dhcp6c 	58179 	DUID: DUID HERE
    Mar 8 11:13:49 	dhcp6c 	58179 	get DHCP option client ID, len 14
    Mar 8 11:13:49 	dhcp6c 	58179 	DUID: DUID HERE
    Mar 8 11:13:49 	dhcp6c 	58179 	get DHCP option server ID, len 10
    Mar 8 11:13:49 	dhcp6c 	58179 	receive advertise from fe80::2c1:aaaa:aaaa:aaaa%pppoe0 on pppoe0
    Mar 8 11:13:49 	dhcp6c 	58179 	reset a timer on pppoe0, state=SOLICIT, timeo=0, retrans=1091
    Mar 8 11:13:49 	dhcp6c 	58179 	send solicit to ff02::1:2%pppoe0
    Mar 8 11:13:49 	dhcp6c 	58179 	set IA_PD
    Mar 8 11:13:49 	dhcp6c 	58179 	set elapsed time (len 2)
    Mar 8 11:13:49 	dhcp6c 	58179 	set client ID (len 14)
    Mar 8 11:13:49 	dhcp6c 	58179 	a new XID (cb9c6c) is generated
    Mar 8 11:13:49 	dhcp6c 	58179 	Sending Solicit
    Mar 8 11:13:48 	dhcp6c 	58179 	reset a timer on pppoe0, state=INIT, timeo=0, retrans=891
    Mar 8 11:13:48 	dhcp6c 	58067 	called
    Mar 8 11:13:48 	dhcp6c 	58067 	called
    Mar 8 11:13:48 	dhcp6c 	58067 	<3>end of sentence [;] (1)
    Mar 8 11:13:48 	dhcp6c 	58067 	<3>end of closure [}] (1)
    Mar 8 11:13:48 	dhcp6c 	58067 	<13>begin of closure [{] (1)
    Mar 8 11:13:48 	dhcp6c 	58067 	<13>[0] (1)
    Mar 8 11:13:48 	dhcp6c 	58067 	<13>[pd] (2)
    Mar 8 11:13:48 	dhcp6c 	58067 	<3>[id-assoc] (8)
    Mar 8 11:13:48 	dhcp6c 	58067 	<3>end of sentence [;] (1)
    Mar 8 11:13:48 	dhcp6c 	58067 	<3>end of closure [}] (1)
    Mar 8 11:13:48 	dhcp6c 	58067 	<3>end of sentence [;] (1)
    Mar 8 11:13:48 	dhcp6c 	58067 	<3>["/var/etc/dhcp6c_opt2_script.sh"] (32)
    Mar 8 11:13:48 	dhcp6c 	58067 	<3>[script] (6)
    Mar 8 11:13:48 	dhcp6c 	58067 	<3>end of sentence [;] (1)
    Mar 8 11:13:48 	dhcp6c 	58067 	<3>[0] (1)
    Mar 8 11:13:48 	dhcp6c 	58067 	<3>[ia-pd] (5)
    Mar 8 11:13:48 	dhcp6c 	58067 	<3>[send] (4)
    Mar 8 11:13:48 	dhcp6c 	58067 	<3>begin of closure [{] (1)
    Mar 8 11:13:48 	dhcp6c 	58067 	<5>[pppoe0] (6)
    Mar 8 11:13:48 	dhcp6c 	58067 	<3>[interface] (9)
    Mar 8 11:13:48 	dhcp6c 	58067 	skip opening control port
    Mar 8 11:13:48 	dhcp6c 	58067 	failed initialize control message authentication
    Mar 8 11:13:48 	dhcp6c 	58067 	failed to open /usr/local/etc/dhcp6cctlkey: No such file or directory
    Mar 8 11:13:48 	dhcp6c 	58067 	extracted an existing DUID from /var/db/dhcp6c_duid: DUID HERE
    
    

    Nad what happens after I disconnect and reconnect UTP cable for 2 seconds:

    
    Mar 8 11:18:45 	dhcp6c 	58179 	exiting
    Mar 8 11:18:45 	dhcp6c 	58179 	script "/var/etc/dhcp6c_opt2_script.sh" terminated
    Mar 8 11:18:45 	dhcp6c 	58179 	executes /var/etc/dhcp6c_opt2_script.sh
    Mar 8 11:18:45 	dhcp6c 	58179 	removing an event on pppoe0, state=RELEASE
    Mar 8 11:18:45 	dhcp6c 	58179 	script "/var/etc/dhcp6c_opt2_script.sh" terminated
    Mar 8 11:18:45 	dhcp6c 	58179 	executes /var/etc/dhcp6c_opt2_script.sh
    Mar 8 11:18:45 	dhcp6c 	58179 	status code: success
    Mar 8 11:18:45 	dhcp6c 	58179 	dhcp6c Received RELEASE
    Mar 8 11:18:45 	dhcp6c 	58179 	status code: no binding
    Mar 8 11:18:45 	dhcp6c 	58179 	get DHCP option status code, len 12
    Mar 8 11:18:45 	dhcp6c 	58179 	IA_PD: ID=0, T1=60, T2=120
    Mar 8 11:18:45 	dhcp6c 	58179 	get DHCP option IA_PD, len 28
    Mar 8 11:18:45 	dhcp6c 	58179 	status code: success
    Mar 8 11:18:45 	dhcp6c 	58179 	get DHCP option status code, len 9
    Mar 8 11:18:45 	dhcp6c 	58179 	DUID: DUID HERE
    Mar 8 11:18:45 	dhcp6c 	58179 	get DHCP option client ID, len 14
    Mar 8 11:18:45 	dhcp6c 	58179 	DUID: DUID HERE
    Mar 8 11:18:45 	dhcp6c 	58179 	get DHCP option server ID, len 10
    Mar 8 11:18:45 	dhcp6c 	58179 	receive reply from fe80::2c1:aaaa:aaaa:aaaa%pppoe0 on pppoe0
    Mar 8 11:18:45 	dhcp6c 	58179 	reset a timer on pppoe0, state=RELEASE, timeo=4, retrans=14498
    Mar 8 11:18:45 	dhcp6c 	58179 	send release to ff02::1:2%pppoe0
    Mar 8 11:18:45 	dhcp6c 	58179 	set IA_PD
    Mar 8 11:18:45 	dhcp6c 	58179 	set IA_PD prefix
    Mar 8 11:18:45 	dhcp6c 	58179 	set elapsed time (len 2)
    Mar 8 11:18:45 	dhcp6c 	58179 	set server ID (len 10)
    Mar 8 11:18:45 	dhcp6c 	58179 	set client ID (len 14)
    Mar 8 11:18:45 	dhcp6c 	58179 	Sending Release
    Mar 8 11:18:38 	dhcp6c 	58179 	reset a timer on pppoe0, state=RELEASE, timeo=3, retrans=7281
    Mar 8 11:18:38 	dhcp6c 	58179 	transmit failed: Can't assign requested address
    Mar 8 11:18:38 	dhcp6c 	58179 	set IA_PD
    Mar 8 11:18:38 	dhcp6c 	58179 	set IA_PD prefix
    Mar 8 11:18:38 	dhcp6c 	58179 	set elapsed time (len 2)
    Mar 8 11:18:38 	dhcp6c 	58179 	set server ID (len 10)
    Mar 8 11:18:38 	dhcp6c 	58179 	set client ID (len 14)
    Mar 8 11:18:38 	dhcp6c 	58179 	Sending Release
    Mar 8 11:18:34 	dhcp6c 	58179 	reset a timer on pppoe0, state=RELEASE, timeo=2, retrans=3606
    Mar 8 11:18:34 	dhcp6c 	58179 	send release to ff02::1:2%pppoe0
    Mar 8 11:18:34 	dhcp6c 	58179 	set IA_PD
    Mar 8 11:18:34 	dhcp6c 	58179 	set IA_PD prefix
    Mar 8 11:18:34 	dhcp6c 	58179 	set elapsed time (len 2)
    Mar 8 11:18:34 	dhcp6c 	58179 	set server ID (len 10)
    Mar 8 11:18:34 	dhcp6c 	58179 	set client ID (len 14)
    Mar 8 11:18:34 	dhcp6c 	58179 	Sending Release
    Mar 8 11:18:33 	dhcp6c 	58179 	reset a timer on pppoe0, state=RELEASE, timeo=1, retrans=1844
    Mar 8 11:18:33 	dhcp6c 	58179 	send release to ff02::1:2%pppoe0
    Mar 8 11:18:33 	dhcp6c 	58179 	set IA_PD
    Mar 8 11:18:33 	dhcp6c 	58179 	set IA_PD prefix
    Mar 8 11:18:33 	dhcp6c 	58179 	set elapsed time (len 2)
    Mar 8 11:18:33 	dhcp6c 	58179 	set server ID (len 10)
    Mar 8 11:18:33 	dhcp6c 	58179 	set client ID (len 14)
    Mar 8 11:18:33 	dhcp6c 	58179 	Sending Release
    Mar 8 11:18:32 	dhcp6c 	58179 	removing an event on pppoe0, state=INIT
    Mar 8 11:18:32 	dhcp6c 	58179 	reset a timer on pppoe0, state=INIT, timeo=0, retrans=256
    Mar 8 11:18:32 	dhcp6c 	58179 	remove a site prefix 2001:xxxx:xxx:xxx::/56
    Mar 8 11:18:32 	dhcp6c 	58179 	remove an IA: PD-0
    Mar 8 11:18:32 	dhcp6c 	58179 	send release to ff02::1:2%pppoe0
    Mar 8 11:18:32 	dhcp6c 	58179 	set IA_PD
    Mar 8 11:18:32 	dhcp6c 	58179 	set IA_PD prefix
    Mar 8 11:18:32 	dhcp6c 	58179 	set elapsed time (len 2)
    Mar 8 11:18:32 	dhcp6c 	58179 	set server ID (len 10)
    Mar 8 11:18:32 	dhcp6c 	58179 	set client ID (len 14)
    Mar 8 11:18:32 	dhcp6c 	58179 	a new XID (7c6018) is generated
    Mar 8 11:18:32 	dhcp6c 	58179 	Sending Release
    Mar 8 11:18:32 	dhcp6c 	58179 	reset a timer on pppoe0, state=RELEASE, timeo=0, retrans=911
    Mar 8 11:18:32 	dhcp6c 	58179 	release an IA: PD-0
    Mar 8 11:18:32 	dhcp6c 	58179 	Start address release 
    
    

    So this is it.

    I`ve tried with "Do not allow PD/Address release", same thing…
    Tried also some other options from GUI, nothing helps.

    Also tried unplugging UTP and let pppoe die completley and same thing.

    If link flaps for 1 second I loose IPv6.

    I posted here before opening redmine ticket to see, if maybe this is config error on my side.

    Thanks in advance :)







  • Awww just saw this: https://redmine.pfsense.org/issues/7330
    Same?



  • I think it is the same …



  • Well we got half working PPPoE then :(

    In addition I`ve noticed that sometimes pppoe does not get IPv6 address and sometimes does.
    IPv6 on hosts works just fine it only affects gateway monitoring (status PENDING always)…

    Sigh...



  • This thing is completley broken…
    It releases my /56 which is ok, then releases my /64 on wan which is also ok, then it renews only wan /64 and not /56 as well... If link even blinks, I'm without IPv6...



  • @maverick_slo:

    This thing is completley broken…
    It releases my /56 which is ok, then releases my /64 on wan which is also ok, then it renews only wan /64 and not /56 as well... If link even blinks, I'm without IPv6...

    One of my testers is suffering from a similar issue, WAN flap causes loss of IPv6 in certain cases. We are working on a fix for it and it may be the same issue that is causing your problem. We think we have nailed it but testing is not complete yet, but so far it's looks to have resolved it.

    Can I ask what hardware you are using, modem and pfsense hardware and which ISP you are with?



  • Hi!
    Modem is some generic ftth crap, I use intel nics and isp is Telekom from my country…
    Care to share fix?



  • Hmm I`ve applied: https://github.com/pfsense/pfsense/pull/3515.diff
    via system patches…

    Same thing, so this does not fix my issue...

    Mar 11 11:10:04 	dhcp6c 	23264 	exiting
    Mar 11 11:10:04 	dhcp6c 	23264 	script "/var/etc/dhcp6c_opt2_script.sh" terminated
    Mar 11 11:10:03 	dhcp6c 		dhcp6c EXIT or RELEASE on pppoe0 running rc.newwanipv6
    Mar 11 11:10:03 	dhcp6c 	23264 	executes /var/etc/dhcp6c_opt2_script.sh
    Mar 11 11:10:03 	dhcp6c 	23264 	removing an event on pppoe0, state=INIT
    Mar 11 11:10:03 	dhcp6c 	23264 	reset a timer on pppoe0, state=INIT, timeo=0, retrans=118
    Mar 11 11:10:03 	dhcp6c 	23264 	remove a site prefix 2001:xxxx:xxx:xxx::/56
    Mar 11 11:10:03 	dhcp6c 	23264 	remove an IA: PD-0
    Mar 11 11:10:03 	dhcp6c 	23264 	Bypassing address release because of -n flag 
    

    So it removes my /56 prefix and after pppoe reconnects prefix never comes back…



  • So what do the logs say when it comes back up. Also need to see youy system logs. As a note, I don't post patch links for processes we are testing, you do that at your own risk.

    Which mode are you running dhcp6c in 'Do not wait for a RA' or default?



  • Above log is what it produces from moment i disconnect utp to a moment pppoe is back up and running.
    I use default mode, so I wait for ra.
    If I set it otherwise it won't work…



  • Can you post your system log showing the same times plus the next sixty seconds. I want to see what RTSOLD is doing.



  • Sure just gimme a sec my 7 month baby is sleeping on me 😁



  • Forgot to ask…
    With or without patch applied?



  • Here in Michigan we're recovering from power problems. Comcast is having trouble keeping their stuff working. To restore IPv6 I:

    LAN
    IPv6 Configuration Type: Static
    IPv6 address: (blank)
    Save
    Ignore error: The following input errors were detected: The field IPv6 address is required.
    IPv6 Configuration Type: Track Interface
    Save
    Apply

    Connectivity is restored.



  • OK without patch…

    DHCP6C logs:

    Mar 11 21:04:46 	dhcp6c 	50640 	exiting
    Mar 11 21:04:46 	dhcp6c 	50640 	script "/var/etc/dhcp6c_opt2_script.sh" terminated
    Mar 11 21:04:46 	dhcp6c 	50640 	executes /var/etc/dhcp6c_opt2_script.sh
    Mar 11 21:04:46 	dhcp6c 	50640 	removing an event on pppoe0, state=INIT
    Mar 11 21:04:46 	dhcp6c 	50640 	reset a timer on pppoe0, state=INIT, timeo=0, retrans=118
    Mar 11 21:04:46 	dhcp6c 	50640 	remove a site prefix 2001:xxxx:xxx:xxx::/56
    Mar 11 21:04:46 	dhcp6c 	50640 	remove an IA: PD-0
    Mar 11 21:04:46 	dhcp6c 	50640 	Bypassing address release because of -n flag 
    

    System log:

    
    Mar 11 21:08:41 	gateway.rasca.local 		nginx: 2017/03/11 21:08:41 [error] 89046#100576: send() failed (54: Connection reset by peer)
    Mar 11 21:08:20 	kernel 		em1_vlan8: promiscuous mode enabled
    Mar 11 21:06:07 	kernel 		em0_vlan7: promiscuous mode enabled
    Mar 11 21:06:07 	kernel 		em0: promiscuous mode enabled
    Mar 11 21:06:07 	SnortStartup 	30040 	Snort START for Snort LAN192(26951_em1_vlan8)...
    Mar 11 21:05:36 	check_reload_status 		Reloading filter
    Mar 11 21:05:36 	check_reload_status 		Syncing firewall
    Mar 11 21:05:33 	php-fpm 	6743 	/rc.start_packages: The command '/usr/local/etc/rc.d/syslog-ng.sh stop' returned exit code '1', the output was ''
    Mar 11 21:05:28 	supervise/syslog-ng 	52432 	Daemon exited gracefully, not restarting; exitcode='0'
    Mar 11 21:05:28 	php-fpm 	6743 	/rc.start_packages: Reloading syslog-ng for configuration sync
    Mar 11 21:05:27 	check_reload_status 		Syncing firewall
    Mar 11 21:05:26 	check_reload_status 		Syncing firewall
    Mar 11 21:05:24 	php-fpm 	6743 	/rc.start_packages: [lightsquid] Updating cronjobs...
    Mar 11 21:05:24 	check_reload_status 		Syncing firewall
    Mar 11 21:05:22 	check_reload_status 		Syncing firewall
    Mar 11 21:05:20 	php-fpm 	6743 	/rc.start_packages: [lightsquid] Removing old cronjobs...
    Mar 11 21:05:20 	php-fpm 	6743 	/rc.start_packages: [lightsquid] Successfully created '/usr/local/etc/lightsquid/lightsquid.cfg' configuration file.
    Mar 11 21:05:20 	php-fpm 	6743 	/rc.start_packages: [lightsquid] Loaded default '/usr/local/etc/lightsquid/lightsquid.cfg.sample' configuration file.
    Mar 11 21:05:20 	check_reload_status 		Reloading filter
    Mar 11 21:05:19 	php-fpm 	6743 	/rc.start_packages: [squid] Starting a proxy monitor script
    Mar 11 21:05:19 	php-fpm 	6743 	/rc.start_packages: [squid] Reloading for configuration sync...
    Mar 11 21:05:18 	php-fpm 	6743 	/rc.start_packages: [squid] Stopping any running proxy monitors
    Mar 11 21:05:18 	check_reload_status 		Syncing firewall
    Mar 11 21:05:16 	php-fpm 	6743 	/rc.start_packages: [squid] Removing freshclam cronjob.
    Mar 11 21:05:16 	php-fpm 	6743 	/rc.start_packages: [squid] Antivirus features disabled.
    Mar 11 21:05:16 	php-fpm 	6743 	/rc.start_packages: [squid] Adding cronjobs ...
    Mar 11 21:05:12 	php-fpm 	6743 	/rc.start_packages: [squid] - squid_resync function call pr:1 bp: rpc:no
    Mar 11 21:05:12 	SnortStartup 	66694 	Ignoring additional START command since Snort is already starting...
    Mar 11 21:05:12 	php-fpm 	6743 	/rc.start_packages: Restarting/Starting all packages.
    Mar 11 21:05:10 	check_reload_status 		Starting packages
    Mar 11 21:05:10 	php-fpm 	83243 	/rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 212.xx.xx.xxx -> 212.xx.xx.xxx - Restarting packages.
    Mar 11 21:05:08 	php-fpm 	83243 	/rc.newwanip: Creating rrd update script
    Mar 11 21:05:08 	php-fpm 	83243 	/rc.newwanip: Resyncing OpenVPN instances for interface PPPOE.
    Mar 11 21:05:06 	dhcpleases 		kqueue error: unkown
    Mar 11 21:05:06 	php-fpm 	83243 	/rc.newwanip: The command '/usr/local/sbin/unbound -c /var/unbound/unbound.conf' returned exit code '1', the output was '[1489262706] unbound[91239:0] error: bind: address already in use [1489262706] unbound[91239:0] fatal error: could not open ports'
    Mar 11 21:05:05 	check_reload_status 		Reloading filter
    Mar 11 21:05:05 	check_reload_status 		updating dyndns opt2
    Mar 11 21:05:03 	dhcpleases 		kqueue error: unkown
    Mar 11 21:05:00 	dhcpleases 		Could not deliver signal HUP to process because its pidfile (/var/run/unbound.pid) does not exist, No such process.
    Mar 11 21:04:59 	dhcpleases 		/etc/hosts changed size from original!
    Mar 11 21:04:58 	php-fpm 	35400 	/rc.filter_configure_sync: Gateways status could not be determined, considering all as up/active. (Group: GWGRP_IPv6)
    Mar 11 21:04:57 	php-fpm 	83243 	/rc.newwanip: Removing static route for monitor 2001:xxxx:xxxx:xxxx:xxxx and adding a new route through fe80::xxx:xxxx:xxxx:xxxx%pppoe0
    Mar 11 21:04:57 	php-fpm 	83243 	/rc.newwanip: ROUTING: setting IPv6 default route to fe80::xxx:xxxx:xxxx:xxxx%pppoe0
    Mar 11 21:04:57 	check_reload_status 		Reloading filter
    Mar 11 21:04:56 	dhcpleases 		Could not deliver signal HUP to process because its pidfile (/var/run/unbound.pid) does not exist, No such process.
    Mar 11 21:04:56 	php-fpm 	83243 	/rc.newwanip: Gateways status could not be determined, considering all as up/active. (Group: GWGRP_IPv6)
    Mar 11 21:04:56 	php-fpm 	83243 	/rc.newwanip: rc.newwanip: on (IP address: xxx.xx.xx.185) (interface: PPPOE[opt2]) (real interface: pppoe0).
    Mar 11 21:04:56 	php-fpm 	83243 	/rc.newwanip: rc.newwanip: Info: starting on pppoe0.
    Mar 11 21:04:55 	php-fpm 	10045 	/rc.newwanipv6: Removing static route for monitor 2001:xxxx:xxxx:xxxx:xxxx and adding a new route through fe80::xxx:xxxx:xxxx:xxxx%pppoe0
    Mar 11 21:04:55 	php-fpm 	10045 	/rc.newwanipv6: ROUTING: setting IPv6 default route to fe80::xxx:xxxx:xxxx:xxxx%pppoe0
    Mar 11 21:04:55 	php-fpm 	10045 	/rc.newwanipv6: rc.newwanipv6: on (IP address: 2001:xxxx:xxx:x:xxx:xxx:xxxx:xxxx) (interface: opt2) (real interface: pppoe0).
    Mar 11 21:04:55 	php-fpm 	10045 	/rc.newwanipv6: rc.newwanipv6: Info: starting on pppoe0.
    Mar 11 21:04:55 	rtsold 		RTSOLD Lock in place
    Mar 11 21:04:55 	rtsold 		Received RA specifying route fe80::xxx:xxxx:xxxx:xxxx for interface opt2(pppoe0)
    Mar 11 21:04:55 	dhcpleases 		/etc/hosts changed size from original!
    Mar 11 21:04:55 	check_reload_status 		rc.newwanip starting pppoe0
    Mar 11 21:04:54 	ppp 		[opt2] xxx.xx.xx.185 -> xxx.xx.xx.174
    Mar 11 21:04:54 	ppp 		[opt2] IPCP: LayerUp
    Mar 11 21:04:54 	ppp 		[opt2] IPCP: state change Ack-Sent --> Opened
    Mar 11 21:04:54 	ppp 		[opt2] IPADDR xxx.xx.xx.185
    Mar 11 21:04:54 	ppp 		[opt2] IPCP: rec'd Configure Ack #3 (Ack-Sent)
    Mar 11 21:04:54 	ppp 		[opt2] IPADDR xxx.xx.xx.185
    Mar 11 21:04:54 	ppp 		[opt2] IPCP: SendConfigReq #3
    Mar 11 21:04:54 	ppp 		[opt2] xxx.xx.xx.185 is OK
    Mar 11 21:04:54 	ppp 		[opt2] IPADDR xxx.xx.xx.185
    Mar 11 21:04:54 	ppp 		[opt2] IPCP: rec'd Configure Nak #2 (Ack-Sent)
    Mar 11 21:04:54 	ppp 		[opt2] IFACE: Rename interface ng0 to pppoe0
    Mar 11 21:04:54 	ppp 		[opt2] IFACE: Up event
    Mar 11 21:04:54 	check_reload_status 		rc.newwanipv6 starting pppoe0
    Mar 11 21:04:54 	check_reload_status 		Restarting ipsec tunnels
    Mar 11 21:04:54 	php-fpm 	66848 	/rc.linkup: ROUTING: setting IPv6 default route to fe80::xxx:xxxx:xxxx:xxxx%pppoe0
    Mar 11 21:04:54 	php 		/usr/local/sbin/ppp-ipv6: Accept router advertisements on interface pppoe0
    Mar 11 21:04:54 	ppp 		[opt2] 020e:xxxx:xxxx:xxxx -> 02c1:xxxx:xxxx:xxxx
    Mar 11 21:04:54 	ppp 		[opt2] IPV6CP: LayerUp
    Mar 11 21:04:54 	ppp 		[opt2] IPV6CP: state change Ack-Sent --> Opened
    Mar 11 21:04:54 	ppp 		[opt2] IPV6CP: rec'd Configure Ack #1 (Ack-Sent)
    Mar 11 21:04:54 	ppp 		[opt2] IPADDR 0.0.0.0
    Mar 11 21:04:54 	ppp 		[opt2] IPCP: SendConfigReq #2
    Mar 11 21:04:54 	ppp 		[opt2] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
    Mar 11 21:04:54 	ppp 		[opt2] IPCP: rec'd Configure Reject #1 (Ack-Sent)
    Mar 11 21:04:54 	ppp 		[opt2] IPV6CP: state change Req-Sent --> Ack-Sent
    Mar 11 21:04:54 	ppp 		[opt2] IPV6CP: SendConfigAck #1
    Mar 11 21:04:54 	ppp 		[opt2] IPV6CP: rec'd Configure Request #1 (Req-Sent)
    Mar 11 21:04:54 	ppp 		[opt2] IPCP: state change Req-Sent --> Ack-Sent
    Mar 11 21:04:54 	ppp 		[opt2] IPADDR xxx.xx.xx.174
    Mar 11 21:04:54 	ppp 		[opt2] IPCP: SendConfigAck #1
    Mar 11 21:04:54 	ppp 		[opt2] xxx.xx.xx.174 is OK
    Mar 11 21:04:54 	ppp 		[opt2] IPADDR xxx.xx.xx.174
    Mar 11 21:04:54 	ppp 		[opt2] IPCP: rec'd Configure Request #1 (Req-Sent)
    Mar 11 21:04:54 	ppp 		[opt2] IPV6CP: SendConfigReq #1
    Mar 11 21:04:54 	ppp 		[opt2] IPV6CP: state change Starting --> Req-Sent
    Mar 11 21:04:54 	ppp 		[opt2] IPV6CP: Up event
    Mar 11 21:04:54 	ppp 		[opt2] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid
    Mar 11 21:04:54 	ppp 		[opt2] IPADDR 0.0.0.0
    Mar 11 21:04:54 	ppp 		[opt2] IPCP: SendConfigReq #1
    Mar 11 21:04:54 	ppp 		[opt2] IPCP: state change Starting --> Req-Sent
    Mar 11 21:04:54 	ppp 		[opt2] IPCP: Up event
    Mar 11 21:04:54 	ppp 		[opt2] IPV6CP: LayerStart
    Mar 11 21:04:54 	ppp 		[opt2] IPV6CP: state change Initial --> Starting
    Mar 11 21:04:54 	ppp 		[opt2] IPV6CP: Open event
    Mar 11 21:04:54 	ppp 		[opt2] IPCP: LayerStart
    Mar 11 21:04:54 	ppp 		[opt2] IPCP: state change Initial --> Starting
    Mar 11 21:04:54 	ppp 		[opt2] IPCP: Open event
    Mar 11 21:04:54 	ppp 		[opt2] Bundle: Status update: up 1 link, total bandwidth 64000 bps
    Mar 11 21:04:54 	ppp 		[opt2_link0] Link: Join bundle "opt2"
    Mar 11 21:04:54 	ppp 		[opt2_link0] Link: Matched action 'bundle "opt2" ""'
    Mar 11 21:04:54 	ppp 		[opt2_link0] LCP: authorization successful
    Mar 11 21:04:54 	ppp 		[opt2_link0] CHAP: rec'd SUCCESS #1 len: 4
    Mar 11 21:04:54 	ppp 		[opt2_link0] CHAP: sending RESPONSE #1 len: 37
    Mar 11 21:04:54 	ppp 		[opt2_link0] CHAP: Using authname "xxxxxx@xxxxx.net"
    Mar 11 21:04:54 	ppp 		[opt2_link0] Name: "asr-bb"
    Mar 11 21:04:54 	ppp 		[opt2_link0] CHAP: rec'd CHALLENGE #1 len: 27
    Mar 11 21:04:54 	ppp 		[opt2_link0] LCP: LayerUp
    Mar 11 21:04:54 	ppp 		[opt2_link0] LCP: auth: peer wants CHAP, I want nothing
    Mar 11 21:04:54 	ppp 		[opt2_link0] LCP: state change Ack-Sent --> Opened
    Mar 11 21:04:54 	ppp 		[opt2_link0] MAGICNUM 0x5g54356
    Mar 11 21:04:54 	ppp 		[opt2_link0] MRU 1492
    Mar 11 21:04:54 	ppp 		[opt2_link0] PROTOCOMP
    Mar 11 21:04:54 	ppp 		[opt2_link0] LCP: rec'd Configure Ack #2 (Ack-Sent)
    Mar 11 21:04:54 	ppp 		[opt2_link0] MAGICNUM 0x5g54356
    Mar 11 21:04:54 	ppp 		[opt2_link0] MRU 1492
    Mar 11 21:04:54 	ppp 		[opt2_link0] PROTOCOMP
    Mar 11 21:04:54 	ppp 		[opt2_link0] LCP: SendConfigReq #2
    Mar 11 21:04:54 	ppp 		[opt2_link0] LCP: state change Req-Sent --> Ack-Sent
    Mar 11 21:04:54 	ppp 		[opt2_link0] MAGICNUM 0x5g54356
    Mar 11 21:04:54 	ppp 		[opt2_link0] AUTHPROTO CHAP MD5
    Mar 11 21:04:54 	ppp 		[opt2_link0] MRU 1492
    Mar 11 21:04:54 	ppp 		[opt2_link0] LCP: SendConfigAck #1
    Mar 11 21:04:54 	ppp 		[opt2_link0] MAGICNUM 0x5g54356
    Mar 11 21:04:54 	ppp 		[opt2_link0] AUTHPROTO CHAP MD5
    Mar 11 21:04:54 	ppp 		[opt2_link0] MRU 1492
    Mar 11 21:04:54 	ppp 		[opt2_link0] LCP: rec'd Configure Request #1 (Req-Sent)
    Mar 11 21:04:52 	ppp 		[opt2_link0] MAGICNUM 0x5g54356
    Mar 11 21:04:52 	ppp 		[opt2_link0] MRU 1492
    Mar 11 21:04:52 	ppp 		[opt2_link0] PROTOCOMP
    Mar 11 21:04:52 	ppp 		[opt2_link0] LCP: SendConfigReq #1
    Mar 11 21:04:52 	ppp 		[opt2_link0] LCP: state change Starting --> Req-Sent
    Mar 11 21:04:52 	ppp 		[opt2_link0] LCP: Up event
    Mar 11 21:04:52 	ppp 		[opt2_link0] Link: UP event
    Mar 11 21:04:52 	ppp 		[opt2_link0] PPPoE: connection successful
    Mar 11 21:04:51 	ppp 		PPPoE: rec'd ACNAME "asr-bb"
    Mar 11 21:04:51 	ppp 		[opt2_link0] PPPoE: Connecting to ''
    Mar 11 21:04:51 	ppp 		[opt2_link0] LCP: LayerStart
    Mar 11 21:04:51 	ppp 		[opt2_link0] LCP: state change Initial --> Starting
    Mar 11 21:04:51 	ppp 		[opt2_link0] LCP: Open event
    Mar 11 21:04:51 	kernel 		ng0: changing name to 'pppoe0'
    Mar 11 21:04:51 	ppp 		[opt2_link0] Link: OPEN event
    Mar 11 21:04:51 	ppp 		[opt2] Bundle: Interface ng0 created
    Mar 11 21:04:51 	ppp 		web: web is not running
    Mar 11 21:04:51 	ppp 		process 4070 terminated
    Mar 11 21:04:51 	ppp 		[opt2_link0] Link: Shutdown
    Mar 11 21:04:51 	ppp 		[opt2] Bundle: Shutdown
    Mar 11 21:04:50 	ppp 		waiting for process 4070 to die...
    Mar 11 21:04:49 	ppp 		waiting for process 4070 to die...
    Mar 11 21:04:49 	ppp 		[opt2_link0] LCP: state change Closed --> Initial
    Mar 11 21:04:49 	ppp 		[opt2_link0] LCP: Down event
    Mar 11 21:04:49 	ppp 		[opt2_link0] Link: DOWN event
    Mar 11 21:04:49 	ppp 		[opt2_link0] LCP: LayerFinish
    Mar 11 21:04:49 	ppp 		[opt2_link0] LCP: state change Closing --> Closed
    Mar 11 21:04:49 	ppp 		[opt2_link0] LCP: rec'd Terminate Ack #3 (Closing)
    Mar 11 21:04:49 	ppp 		[opt2_link0] LCP: LayerDown
    Mar 11 21:04:49 	ppp 		[opt2_link0] LCP: SendTerminateReq #3
    Mar 11 21:04:49 	ppp 		[opt2] IPV6CP: state change Closed --> Initial
    Mar 11 21:04:49 	ppp 		[opt2] IPV6CP: Down event
    Mar 11 21:04:49 	ppp 		[opt2] IPCP: state change Closed --> Initial
    Mar 11 21:04:49 	ppp 		[opt2] IPCP: Down event
    Mar 11 21:04:49 	ppp 		[opt2] IPV6CP: Close event
    Mar 11 21:04:49 	ppp 		[opt2] IPCP: Close event
    Mar 11 21:04:49 	ppp 		[opt2] Bundle: Status update: up 0 links, total bandwidth 9600 bps
    Mar 11 21:04:49 	ppp 		[opt2_link0] Link: Leave bundle "opt2"
    Mar 11 21:04:49 	ppp 		[opt2_link0] LCP: state change Opened --> Closing
    Mar 11 21:04:49 	ppp 		[opt2_link0] LCP: Close event
    Mar 11 21:04:49 	ppp 		[opt2_link0] Link: CLOSE event
    Mar 11 21:04:49 	ppp 		[opt2] IPCP: rec'd Terminate Ack #5 (Closed)
    Mar 11 21:04:49 	ppp 		[opt2] IPV6CP: rec'd Terminate Ack #3 (Closed)
    Mar 11 21:04:49 	ppp 		[opt2] Bundle: closing link "opt2_link0"...
    Mar 11 21:04:49 	ppp 		[opt2] Bundle: No NCPs left. Closing links...
    Mar 11 21:04:49 	ppp 		[opt2] IPV6CP: LayerFinish
    Mar 11 21:04:49 	ppp 		[opt2] IPV6CP: state change Closing --> Closed
    Mar 11 21:04:49 	ppp 		[opt2] IPV6CP: rec'd Terminate Ack #2 (Closing)
    Mar 11 21:04:49 	ppp 		[opt2] IPCP: LayerFinish
    Mar 11 21:04:49 	ppp 		[opt2] IPCP: state change Closing --> Closed
    Mar 11 21:04:49 	ppp 		[opt2] IPCP: rec'd Terminate Ack #4 (Closing)
    Mar 11 21:04:49 	ppp 		[opt2] IPCP: SendTerminateReq #5
    Mar 11 21:04:49 	ppp 		[opt2] IPV6CP: SendTerminateReq #3
    Mar 11 21:04:49 	ppp 		[opt2] IFACE: Rename interface pppoe0 to pppoe0
    Mar 11 21:04:49 	ppp 		[opt2] IFACE: Down event
    Mar 11 21:04:49 	check_reload_status 		Rewriting resolv.conf
    Mar 11 21:04:48 	ppp 		waiting for process 4070 to die...
    Mar 11 21:04:47 	ppp 		waiting for process 4070 to die...
    Mar 11 21:04:46 	ppp 		waiting for process 4070 to die...
    Mar 11 21:04:46 	php-fpm 	72868 	/rc.newwanipv6: rc.newwanipv6: No IPv6 address found for interface PPPOE [opt2].
    Mar 11 21:04:46 	php-fpm 	72868 	/rc.newwanipv6: rc.newwanipv6: Info: starting on pppoe0.
    Mar 11 21:04:45 	ppp 		waiting for process 4070 to die...
    Mar 11 21:04:45 	ppp 		[opt2] IPV6CP: LayerDown
    Mar 11 21:04:45 	ppp 		[opt2] IPV6CP: SendTerminateReq #2
    Mar 11 21:04:45 	ppp 		[opt2] IPV6CP: state change Opened --> Closing
    Mar 11 21:04:45 	ppp 		[opt2] IPV6CP: Close event
    Mar 11 21:04:45 	ppp 		[opt2] IFACE: Removing IPv4 address from pppoe0 failed(IGNORING for now. This should be only for PPPoE friendly!): Can't assign requested address
    Mar 11 21:04:45 	check_reload_status 		Rewriting resolv.conf
    Mar 11 21:04:44 	ppp 		[opt2] IPCP: LayerDown
    Mar 11 21:04:44 	ppp 		[opt2] IPCP: SendTerminateReq #4
    Mar 11 21:04:44 	ppp 		[opt2] IPCP: state change Opened --> Closing
    Mar 11 21:04:44 	ppp 		[opt2] IPCP: Close event
    Mar 11 21:04:44 	ppp 		[opt2] IFACE: Close event
    Mar 11 21:04:44 	ppp 		caught fatal signal TERM
    Mar 11 21:04:44 	ppp 		waiting for process 4070 to die...
    Mar 11 21:04:44 	ppp 		process 72353 started, version 5.8 (nobody@pfSense_master_amd64-pfSense_devel-job-04 20:47 20-Oct-2016)
    Mar 11 21:04:44 	ppp 		Multi-link PPP daemon for FreeBSD
    Mar 11 21:04:43 	kernel 		em3: link state changed to UP
    Mar 11 21:04:43 	check_reload_status 		Linkup starting em3
    Mar 11 21:04:39 	check_reload_status 		Reloading filter
    Mar 11 21:04:38 	kernel 		em3: link state changed to DOWN
    Mar 11 21:04:38 	check_reload_status 		Linkup starting em3 
    
    

    BR



  • On disconnect via interfaces page and reconnect there is this in syslog:

    Mar 11 21:19:47 rtsold Starting dhcp6 client for interface opt2(pppoe0)
    Mar 11 21:19:47 rtsold Received RA specifying route fe80::xxx:xxxx:xxxx:xxxxfor interface opt2(pppoe0)

    So it is not removing lock when PPPoE is disconnected via link event.
    If you disconnect pppoe via interfaces page then it removes lock and runs dhcp6 client just fine.



  • @maverick_slo:

    On disconnect via interfaces page and reconnect there is this in syslog:

    Mar 11 21:19:47 rtsold Starting dhcp6 client for interface opt2(pppoe0)
    Mar 11 21:19:47 rtsold Received RA specifying route fe80::xxx:xxxx:xxxx:xxxxfor interface opt2(pppoe0)

    So it is not removing lock when PPPoE is disconnected via link event.
    If you disconnect pppoe via interfaces page then it removes lock and runs dhcp6 client just fine.

    Yes, and that works, now pull the cable and show the system log that  gets displayed there.

    Also, can you add this patch, do not remove the others, just add this one and see if it makes any difference. It's the only other place I can find where dhcp6c is killed directly. It needs to be killed using a process, that process also removes any locks.

    2d81d94e1d96dacae82cf4c60a4f069c066d22ec



  • Ummm see post before last one.. There are logs what happens on cable unplug…
    Tried patch aswell same results...



  • And that is not what the log should say if you have the correct patches in place.

    Mar 11 21:04:55 rtsold RTSOLD Lock in place

    has been replaced.

    The current debug message says "RTSOLD Lock in place - sending SIGHUP to dhcp6c.". I changed it so I could be sure testers were running the correct patches.

    The patches are:

    718cbc2d3921627e9767e59d539386c843dffcc4
    ea4de27b15441763bd227a2a942df522d98775c8
    2d81d94e1d96dacae82cf4c60a4f069c066d22ec

    Applied in that order.

    And one more to add, just found another posix_kill() that would leave the lock behind.

    e660bd4f34245958a290240c04afacb0823d4b74



  • Hmm yes I know it changed to RTSOLD Lock in place - sending SIGHUP to dhcp6c. But patch unfortunatley has no effect. Will try latest tomorrow and report back.



  • Hehe now you nailed it :)
    It works perfect with one exception which I dont know if its related…

    Tried 10 times.
    6 times all ok but in 4 times I got no IPv6 address on my pppoe iface.
    Everything works as expected exept gateway monitoring (it shows status pending because ipv6 address is missing on ppoe).

    I don`t know why it happens it seems really random.

    Thanks!



  • Ha! Managed to replicate when pppoe does not obtain ipv6 address…

    So if link flaps for 10 seconds or just modem reboots there is no problem.

    But when link is down more than that and LCP echo requests start to fail or pppoe reconnect after 5th LCP missing is exectuted, then pppoe does NOT obtain IPv6 address and gateway is marked as pending.
    IPv6 from firewall and subnets is working just fine, again just gateway monitoring is impacted...

    BR,
    Greg



  • That's good news. My bad for not thouroughly checking for any other posix_Kill() calls for dhcp6c so sorry for that.

    I have noticed that sometimes the gateway monitor does not reflect the real state after an up/down event. I tend to no believe it if I can see the addresses are all there and just leave it, the page refresh always seems to sort it out after a while.

    I'll merge those commits into one later today and update the PR.


  • Banned

    @marjohn56:

    The patches are:

    718cbc2d3921627e9767e59d539386c843dffcc4
    ea4de27b15441763bd227a2a942df522d98775c8
    2d81d94e1d96dacae82cf4c60a4f069c066d22ec
    e660bd4f34245958a290240c04afacb0823d4b74

    At the risk of looking dense - what patches where? Is there some PR for this?



  • I would be sarcastic but Ill leave that to you good ol doc :)

    https://github.com/pfsense/pfsense/pull/3515



  • @maverick_slo:

    I would be sarcastic but Ill leave that to you good ol doc :)

    https://github.com/pfsense/pfsense/pull/3515

    :D

    Note that if you apply the lot you'll get REASONS working too, you should see some effects from dhcp6 renews no longer triggering wan updates, makes the logs much quieter.


  • Banned

    I did not mean to be sarcastic, I wanted to make sure that there's a proper PR for this, otherwise you end up with half of the patches getting lost and things broken



  • J/K :)

    About my IPv6 on pppoe iface issue, should I start new thread/redmine or is it somehow connected to this?



  • @maverick_slo:

    J/K :)

    About my IPv6 on pppoe iface issue, should I start new thread/redmine or is it somehow connected to this?

    It's ALL related in there somewhere, but gateway monitoring is not an area of pfsense I'm familiar with, so whether its related to locks and reasons, i'm summing the two, or something else thats always been there I have no idea… at the moment.



  • I'll snapshot my test system and do the patches, then I'll throw some curved balls at it and see if I can replicate the monitoring issue. On a side note, I'm changing ISP in a couple of weeks and my v6 will no longer be dhcp6 without RA ( that's a mismomer and we should change it! ) but similar to Mav*Slo, so I will be able to see exactly what's going on there.



  • No no, gateway monitoring is just consequence…

    Look what I mean:

    When things are 100% OK:

    
    Status
        up
    PPPoE
        up 
    Uptime
        00:01:50
    MAC Address
        00:00:00:00:00:00
    IPv4 Address
        212.xx.xx.xxx
    Subnet mask IPv4
        255.255.255.255
    Gateway IPv4
        212.xx.xx.xxx
    IPv6 Link Local
        fe80::xxx:xxx:xxxx:xxxx%pppoe0
    IPv6 Address
        2001:xxxx:xxx:x:xxx:xxx:xxxx:xxxx
    Subnet mask IPv6
        64
    Gateway IPv6
        fe80::xxx:xxxx:xxxx:xxxx
    MTU
        1492
    In/out packets
        1543787/651379 (1.61 GiB/46.27 MiB)
    In/out packets (pass)
        1543787/651379 (1.61 GiB/46.27 MiB)
    In/out packets (block)
        2393/0 (137 KiB/0 B)
    In/out errors
        0/0
    Collisions
        0
    
    

    And when there is no IPv6 on PPPoe:

    
    Status
        up
    PPPoE
        up 
    Uptime
        00:00:23
    MAC Address
        00:00:00:00:00:00
    IPv4 Address
        212.xx.xx.xxx
    Subnet mask IPv4
        255.255.255.255
    Gateway IPv4
        212.xx.xx.xxx
    IPv6 Link Local
        fe80::xxx:xxx:xxxx:xxxx%pppoe0
    Gateway IPv6
        fe80::xxx:xxxx:xxxx:xxxx
    MTU
        1492
    In/out packets
        1545272/656932 (1.61 GiB/46.65 MiB)
    In/out packets (pass)
        1545272/656932 (1.61 GiB/46.65 MiB)
    In/out packets (block)
        2418/0 (137 KiB/0 B)
    In/out errors
        0/0
    Collisions
        0
    
    


  • Can you do a test for me, go to the shell, and firstly check that dhcp6c is running, if it is, then can you send it a SIGHUP, SIGHUP being  'kill -1 PID', see if that makes it recover.



  • DHCP6c IS running.

    root    39375   0.9  0.1   8348   2328  -  Ss   10:04      0:00.00 /usr/local/sbin/dhcp6c -D -c /var/etc/dhcp6c_opt2.conf -p /var/run/dhcp6c_pppoe0.pid pppoe0
    

    Killed it:

    
    kill -1 39375
    
    

    No change on pppoe :(



  • And quite a lot of:

    
    Mar 12 10:14:33 	php-fpm 	80662 	/rc.newwanip: ROUTING: setting IPv6 default route to fe80::xxx:xxx:xxxx:xxxx%pppoe0
    Mar 12 10:14:33 	php-fpm 	60486 	/rc.newwanipv6: rc.newwanipv6: No IPv6 address found for interface PPPOE [opt2].
    Mar 12 10:14:33 	php-fpm 	60486 	/rc.newwanipv6: rc.newwanipv6: Info: starting on pppoe0\. 
    Mar 12 10:14:31 	php-fpm 	80662 	/rc.newwanipv6: rc.newwanipv6: No IPv6 address found for interface PPPOE [opt2].
    Mar 12 10:14:31 	php-fpm 	80662 	/rc.newwanipv6: rc.newwanipv6: Info: starting on pppoe0.
    Mar 12 10:14:31 	rtsold 		Starting dhcp6 client for interface opt2(pppoe0)
    Mar 12 10:14:31 	rtsold 		Received RA specifying route fe80::xxx:xxx:xxxx:xxxx for interface opt2(pppoe0) 
    
    


  • What do the dhcp logs show at that moment?



  • Actually same as when it works…  I see nothing special there...



  • So it appears dhcp6c is working, and by the look of it so is RTSOLD. Hmm, pppoe thing. Not even sure if it's related or not.

    Try this, see if it makes any difference. Just add it on the end of the others.

    c3b55b8a0aee8fde7474738d08a993ed32ee3282



  • Parse error: syntax error, unexpected ')' in /etc/inc/interfaces.inc on line 3303 Call Stack: 0.0001 226808 1. {main}() /usr/local/www/system_patches.php:0 0.0002 227304 2. require('/usr/local/www/guiconfig.inc') /usr/local/www/system_patches.php:29 0.0005 248832 3. require_once('/etc/inc/authgui.inc') /usr/local/www/guiconfig.inc:47 0.0005 249416 4. include_once('/etc/inc/auth.inc') /etc/inc/authgui.inc:25 0.0005 249848 5. require_once('/etc/inc/config.gui.inc') /etc/inc/auth.inc:30 0.0015 270984 6. require_once('/etc/inc/notices.inc') /etc/inc/config.gui.inc:37 0.0016 271392 7. require_once('/etc/inc/functions.inc') /etc/inc/notices.inc:24

    :(



  • Nuts… Didn't test it.. Give me ten minutes.



  • Fixed it myself…
    Just removed extra ")"... testing now


Log in to reply