Bug #11035
closedPPPoE: can't remove hook
0%
Description
I have seen this with 2 Pfsense.
After changing a single RAW interface (change from none to staticIP on igb4/opt11 or removing staticIP) and apply the settings both PPPoE interface are going down and never up.
The first pfsense I rescued because it has a third none PPPoE wan. The second pfsense is still offline because it has only 2 PPPoE wans.
If I save the pppoe settings (without changing) and apply config the pppoe interfaces went online again.
Nov 5 17:22:43 ppp [opt2_link0] can't remove hook mpd23778-0 from node "[28]:": No such file or directory Nov 5 17:22:43 ppp [opt2_link0] PPPoE: can't connect "[28]:"->"mpd23778-0" and "[26]:"->"left": No such file or directory Nov 5 17:22:43 ppp [opt2_link0] Link: reconnection attempt 187 Nov 5 17:22:41 ppp [opt1] IPV6CP: Close event Nov 5 17:22:41 ppp [opt1] IPCP: Close event Nov 5 17:22:41 ppp [opt1] IFACE: Close event Nov 5 17:22:41 ppp caught fatal signal TERM Nov 5 17:22:41 ppp [opt1_link0] Link: reconnection attempt 188 in 4 seconds Nov 5 17:22:41 ppp [opt1_link0] LCP: Down event Nov 5 17:22:41 ppp [opt1_link0] Link: DOWN event Nov 5 17:22:41 ppp [opt1_link0] can't remove hook mpd12440-0 from node "[1d]:": No such file or directory Nov 5 17:22:41 ppp [opt1_link0] PPPoE: can't connect "[1d]:"->"mpd12440-0" and "[334]:"->"left": No such file or directory Nov 5 17:22:41 ppp [opt1_link0] Link: reconnection attempt 187
<ppps> <ppp> <ptpid>0</ptpid> <type>pppoe</type> <if>pppoe0</if> <ports>igb4.7</ports> <username><![CDATA[xxx]]></username> <password><![CDATA[xxx]]></password> <provider></provider> <bandwidth></bandwidth> <mtu></mtu> <mru></mru> <mrru></mrru> </ppp> <ppp> <ptpid>1</ptpid> <type>pppoe</type> <if>pppoe1</if> <ports>igb5.7</ports> <username><![CDATA[xxx]]></username> <password><![CDATA[xxx]]></password> <descr><![CDATA[VDSL]]></descr> <provider></provider> <bandwidth></bandwidth> <mtu></mtu> <mru></mru> <mrru></mrru> </ppp> </ppps>
<vlan> <if>igb4</if> <tag>7</tag> <pcp></pcp> <descr><![CDATA[3_VDSL]]></descr> <vlanif>igb4.7</vlanif> </vlan> <vlan> <if>igb5</if> <tag>7</tag> <pcp></pcp> <descr><![CDATA[4_VDSL]]></descr> <vlanif>igb5.7</vlanif> </vlan>
<opt3> <if>igb5</if> <descr><![CDATA[4_VDSL_MODEM]]></descr> <spoofmac></spoofmac> <enable></enable> <ipaddr>192.168.16.100</ipaddr> <subnet>24</subnet> </opt3> <opt11> <descr><![CDATA[3_VDSL_Modem]]></descr> <if>igb4</if> <enable></enable> <spoofmac></spoofmac> <ipaddr>192.168.1.100</ipaddr> <subnet>24</subnet> </opt11>
<rule> <source> <network>any</network> </source> <sourceport></sourceport> <descr><![CDATA[NAT VDSL Modem]]></descr> <target></target> <targetip></targetip> <targetip_subnet></targetip_subnet> <interface>opt3</interface> <poolopts></poolopts> <source_hash_key></source_hash_key> <destination> <any></any> </destination> </rule> <rule> <source> <network>any</network> </source> <sourceport></sourceport> <descr></descr> <target></target> <targetip></targetip> <targetip_subnet>0</targetip_subnet> <interface>opt11</interface> <poolopts></poolopts> <destination> <any></any> </destination> </rule>
3_VDSL_MODEM Interface (opt11, igb4) Status up MAC Address 0c:c4:7a:fe:3c:f0 - Super Micro Computer IPv4 Address 192.168.1.100 Subnet mask IPv4 255.255.255.0 IPv6 Link Local fe80::ec4:7aff:fefe:3cf0%igb4 MTU 1500 Media 1000baseT <full-duplex> In/out packets 0/896 (0 B/67 KiB) In/out packets (pass) 0/896 (0 B/67 KiB) In/out packets (block) 4926/0 (1.40 MiB/0 B) In/out errors 0/0 Collisions 0
4_VDSL_MODEM Interface (opt3, igb5) Status up MAC Address 0c:c4:7a:fe:3c:f1 - Super Micro Computer IPv4 Address 192.168.16.100 Subnet mask IPv4 255.255.255.0 IPv6 Link Local fe80::ec4:7aff:fefe:3cf1%igb5 MTU 1500 Media 1000baseT <full-duplex> In/out packets 0/0 (0 B/0 B) In/out packets (pass) 0/0 (0 B/0 B) In/out packets (block) 4852/0 (1.38 MiB/0 B) In/out errors 0/0 Collisions 0
3_VDSL Interface (opt1, pppoe0) Status up PPPoE up Uptime 00:32:38 IPv4 Address 80.153.X.X Subnet mask IPv4 255.255.255.255 Gateway IPv4 62.156.244.24 IPv6 Link Local fe80::ec4:7aff:fefe:3cec%pppoe0 IPv6 Address 2003:a:77f::XXX Subnet mask IPv6 64 Gateway IPv6 fe80::200:ff:fe00:0 MTU 1492 In/out packets 1681740435/1683044277 (1.45 TiB/720.01 GiB) In/out packets (pass) 1681740435/1683044277 (1.45 TiB/720.01 GiB) In/out packets (block) 4037402/210970 (456.15 MiB/48.21 MiB) In/out errors 0/0 Collisions 0
4_VDSL Interface (opt2, pppoe1) Status up PPPoE up Uptime 00:32:15 IPv4 Address 87.139.X.X Subnet mask IPv4 255.255.255.255 Gateway IPv4 62.156.244.32 IPv6 Link Local fe80::ec4:7aff:fefe:3cec%pppoe1 IPv6 Address 2003:a:c7f::XXX Subnet mask IPv6 64 Gateway IPv6 fe80::200:ff:fe00:0 MTU 1492 In/out packets 576675829/556392173 (188.53 GiB/190.93 GiB) In/out packets (pass) 576675829/556392173 (188.53 GiB/190.93 GiB) In/out packets (block) 4140794/1 (423.75 MiB/148 B) In/out errors 0/0 Collisions 0
Updated by Grischa Zengel about 4 years ago
I replayed this bug again:
Nov 5 20:27:09 ppp [opt1_link0] Link: reconnection attempt 6 in 2 seconds Nov 5 20:27:09 ppp [opt1_link0] LCP: Down event Nov 5 20:27:09 ppp [opt1_link0] Link: DOWN event Nov 5 20:27:09 ppp [opt1_link0] can't remove hook mpd92160-0 from node "[620]:": No such file or directory Nov 5 20:27:09 ppp [opt1_link0] PPPoE: can't connect "[620]:"->"mpd92160-0" and "[61e]:"->"left": No such file or directory Nov 5 20:27:09 ppp [opt1_link0] Link: reconnection attempt 5 Nov 5 20:27:09 ppp [opt2_link0] Link: reconnection attempt 5 in 4 seconds Nov 5 20:27:09 ppp [opt2_link0] LCP: Down event Nov 5 20:27:09 ppp [opt2_link0] Link: DOWN event Nov 5 20:27:09 ppp [opt2_link0] can't remove hook mpd32964-0 from node "[630]:": No such file or directory Nov 5 20:27:09 ppp [opt2_link0] PPPoE: can't connect "[630]:"->"mpd32964-0" and "[62e]:"->"left": No such file or directory Nov 5 20:27:09 ppp [opt2_link0] Link: reconnection attempt 4 Nov 5 20:27:08 check_reload_status Reloading filter Nov 5 20:27:08 php-fpm 21004 /rc.newipsecdns: IPSEC: One or more IPsec tunnel endpoints has changed its IP. Refreshing. Nov 5 20:27:07 ppp [opt2_link0] Link: reconnection attempt 4 in 2 seconds Nov 5 20:27:07 ppp [opt2_link0] LCP: Down event Nov 5 20:27:07 ppp [opt2_link0] Link: DOWN event Nov 5 20:27:07 ppp [opt2_link0] can't remove hook mpd32964-0 from node "[630]:": No such file or directory Nov 5 20:27:07 ppp [opt2_link0] PPPoE: can't connect "[630]:"->"mpd32964-0" and "[62e]:"->"left": No such file or directory Nov 5 20:27:07 ppp [opt2_link0] Link: reconnection attempt 3 Nov 5 20:27:05 ppp [opt1_link0] Link: reconnection attempt 5 in 4 seconds Nov 5 20:27:05 ppp [opt1_link0] LCP: Down event Nov 5 20:27:05 ppp [opt1_link0] Link: DOWN event Nov 5 20:27:05 ppp [opt1_link0] can't remove hook mpd92160-0 from node "[620]:": No such file or directory Nov 5 20:27:05 ppp [opt1_link0] PPPoE: can't connect "[620]:"->"mpd92160-0" and "[61e]:"->"left": No such file or directory Nov 5 20:27:05 ppp [opt1_link0] Link: reconnection attempt 4 Nov 5 20:27:04 ppp [opt1_link0] Link: reconnection attempt 4 in 1 seconds Nov 5 20:27:04 ppp [opt1_link0] LCP: Down event Nov 5 20:27:04 ppp [opt1_link0] Link: DOWN event Nov 5 20:27:04 ppp [opt1_link0] can't remove hook mpd92160-0 from node "[620]:": No such file or directory Nov 5 20:27:04 ppp [opt1_link0] PPPoE: can't connect "[620]:"->"mpd92160-0" and "[61e]:"->"left": No such file or directory Nov 5 20:27:04 ppp [opt1_link0] Link: reconnection attempt 3 Nov 5 20:27:04 ppp [opt2_link0] Link: reconnection attempt 3 in 3 seconds Nov 5 20:27:04 ppp [opt2_link0] LCP: Down event Nov 5 20:27:04 ppp [opt2_link0] Link: DOWN event Nov 5 20:27:04 ppp [opt2_link0] can't remove hook mpd32964-0 from node "[630]:": No such file or directory Nov 5 20:27:04 ppp [opt2_link0] PPPoE: can't connect "[630]:"->"mpd32964-0" and "[62e]:"->"left": No such file or directory Nov 5 20:27:04 ppp [opt2_link0] Link: reconnection attempt 2 Nov 5 20:27:04 php-fpm 1997 /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use GW_KV_SAFENET. Nov 5 20:27:04 php-fpm 1997 /rc.openvpn: Gateway, none 'available' for inet6, use the first one configured. '4_VDSL_DHCP6' Nov 5 20:27:04 php-fpm 88264 /rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use GW_TI_KONNEKTOR. Nov 5 20:27:04 php-fpm 88264 /rc.openvpn: Gateway, none 'available' for inet6, use the first one configured. '4_VDSL_DHCP6' Nov 5 20:27:03 ppp [opt1_link0] Link: reconnection attempt 3 in 1 seconds Nov 5 20:27:03 ppp [opt1_link0] LCP: Down event Nov 5 20:27:03 ppp [opt1_link0] Link: DOWN event Nov 5 20:27:03 ppp [opt1_link0] can't remove hook mpd92160-0 from node "[620]:": No such file or directory Nov 5 20:27:03 ppp [opt1_link0] PPPoE: can't connect "[620]:"->"mpd92160-0" and "[61e]:"->"left": No such file or directory Nov 5 20:27:03 ppp [opt1_link0] Link: reconnection attempt 2 Nov 5 20:27:03 php-fpm 21314 /rc.filter_configure_sync: Default gateway setting Gateway Inexio 10M as default. Nov 5 20:27:03 php-fpm 21314 /rc.filter_configure_sync: Gateway, switch to: GW_Inexio10M Nov 5 20:27:03 check_reload_status Restarting OpenVPN tunnels/interfaces Nov 5 20:27:03 check_reload_status Restarting ipsec tunnels Nov 5 20:27:03 check_reload_status updating dyndns GW_KV_SAFENET Nov 5 20:27:03 check_reload_status Reloading filter Nov 5 20:27:03 check_reload_status Restarting OpenVPN tunnels/interfaces Nov 5 20:27:03 check_reload_status Restarting ipsec tunnels Nov 5 20:27:03 check_reload_status updating dyndns GW_TI_KONNEKTOR Nov 5 20:27:03 rc.gateway_alarm 53603 >>> Gateway alarm: GW_KV_SAFENET (Addr:188.144.12.150 Alarm:1 RTT:0.000ms RTTsd:0.000ms Loss:100%) Nov 5 20:27:03 rc.gateway_alarm 52945 >>> Gateway alarm: GW_TI_KONNEKTOR (Addr:192.168.213.50 Alarm:1 RTT:0.000ms RTTsd:0.000ms Loss:100%) Nov 5 20:27:01 kernel sa6_recoverscope: embedded scope mismatch: fe80:14::200:ff:fe00:0%19. sin6_scope_id was overridden Nov 5 20:27:01 kernel sa6_recoverscope: embedded scope mismatch: fe80:14::200:ff:fe00:0%19. sin6_scope_id was overridden Nov 5 20:27:01 ppp [opt2_link0] Link: reconnection attempt 2 in 3 seconds Nov 5 20:27:01 ppp [opt2_link0] LCP: Down event Nov 5 20:27:01 ppp [opt2_link0] Link: DOWN event Nov 5 20:27:01 ppp [opt2_link0] can't remove hook mpd32964-0 from node "[630]:": No such file or directory Nov 5 20:27:01 ppp [opt2_link0] PPPoE: can't connect "[630]:"->"mpd32964-0" and "[62e]:"->"left": No such file or directory Nov 5 20:27:01 ppp [opt2_link0] Link: reconnection attempt 1 Nov 5 20:27:01 php-fpm 168 /interfaces.php: Creating rrd update script Nov 5 20:27:01 check_reload_status Reloading filter Nov 5 20:27:01 php-fpm 168 /interfaces.php: Removing static route for monitor 188.144.12.150 and adding a new route through 192.168.254.10 Nov 5 20:27:01 snmpd 81980 disk_OS_get_disks: adding device 'nvd0' to device list Nov 5 20:27:01 php-fpm 168 /interfaces.php: Removing static route for monitor 77.244.98.5 and adding a new route through 131.117.149.177 Nov 5 20:27:00 ppp [opt1_link0] Link: reconnection attempt 2 in 3 seconds Nov 5 20:27:00 ppp [opt1_link0] LCP: Down event Nov 5 20:27:00 ppp [opt1_link0] Link: DOWN event Nov 5 20:27:00 ppp [opt1_link0] can't remove hook mpd92160-0 from node "[620]:": No such file or directory Nov 5 20:27:00 ppp [opt1_link0] PPPoE: can't connect "[620]:"->"mpd92160-0" and "[61e]:"->"left": No such file or directory Nov 5 20:27:00 ppp [opt1_link0] Link: reconnection attempt 1 Nov 5 20:27:00 php-fpm /rc.resolv_conf_generate: The command '/sbin/route delete -host 1.1.1.1' returned exit code '1', the output was 'route: route has not been found delete host 1.1.1.1 fib 0: not in table' Nov 5 20:27:00 php-fpm /rc.resolv_conf_generate: The command '/sbin/route delete -host 9.9.9.9' returned exit code '1', the output was 'route: route has not been found delete host 9.9.9.9 fib 0: not in table' Nov 5 20:27:00 php-fpm 21314 /rc.resolv_conf_generate: The command '/sbin/route delete -host 1.1.1.1' returned exit code '1', the output was 'route: route has not been found delete host 1.1.1.1 fib 0: not in table' Nov 5 20:27:00 php-fpm 21314 /rc.resolv_conf_generate: The command '/sbin/route delete -host 9.9.9.9' returned exit code '1', the output was 'route: route has not been found delete host 9.9.9.9 fib 0: not in table' Nov 5 20:27:00 php-fpm /rc.dyndns.update: Gateway, switch to: Nov 5 20:26:59 ppp [opt2_link0] Link: reconnection attempt 1 in 2 seconds Nov 5 20:26:59 ppp [opt2_link0] LCP: LayerDown Nov 5 20:26:59 ppp [opt2] IPV6CP: state change Closing --> Initial Nov 5 20:26:59 ppp [opt2] Bundle: No NCPs left. Closing links... Nov 5 20:26:59 ppp [opt2] IPV6CP: LayerFinish Nov 5 20:26:59 ppp [opt2] IPV6CP: Down event Nov 5 20:26:59 ppp [opt2] IPCP: state change Closing --> Initial Nov 5 20:26:59 ppp [opt2] IPCP: LayerFinish Nov 5 20:26:59 ppp [opt2] IPCP: Down event Nov 5 20:26:59 ppp [opt2] IFACE: Rename interface pppoe1 to pppoe1 Nov 5 20:26:59 ppp [opt2] IFACE: Down event Nov 5 20:26:59 ppp [opt1_link0] Link: reconnection attempt 1 in 1 seconds Nov 5 20:26:59 ppp [opt1_link0] LCP: LayerDown Nov 5 20:26:59 ppp [opt1] IPV6CP: state change Closing --> Initial Nov 5 20:26:59 ppp [opt1] Bundle: No NCPs left. Closing links... Nov 5 20:26:59 ppp [opt1] IPV6CP: LayerFinish Nov 5 20:26:59 ppp [opt1] IPV6CP: Down event Nov 5 20:26:59 ppp [opt1] IPCP: state change Closing --> Initial Nov 5 20:26:59 ppp [opt1] IPCP: LayerFinish Nov 5 20:26:59 ppp [opt1] IPCP: Down event Nov 5 20:26:59 ppp [opt1] IFACE: Rename interface pppoe0 to pppoe0 Nov 5 20:26:59 ppp [opt1] IFACE: Down event Nov 5 20:26:59 ppp [opt2] IPV6CP: LayerDown Nov 5 20:26:59 ppp [opt2] IPV6CP: SendTerminateReq #2 Nov 5 20:26:59 ppp [opt2] IPV6CP: state change Opened --> Closing Nov 5 20:26:59 ppp [opt2] IPV6CP: Close event Nov 5 20:26:59 check_reload_status Rewriting resolv.conf Nov 5 20:26:59 ppp [opt1] IPV6CP: LayerDown Nov 5 20:26:59 ppp [opt1] IPV6CP: SendTerminateReq #2 Nov 5 20:26:59 ppp [opt1] IPV6CP: state change Opened --> Closing Nov 5 20:26:59 ppp [opt1] IPV6CP: Close event Nov 5 20:26:59 check_reload_status Rewriting resolv.conf Nov 5 20:26:59 kernel vlan3: changing name to 'igb5.7' Nov 5 20:26:59 ppp [opt2] IPCP: LayerDown Nov 5 20:26:59 ppp [opt2] IPCP: SendTerminateReq #4 Nov 5 20:26:59 ppp [opt2] IPCP: state change Opened --> Closing Nov 5 20:26:59 ppp [opt2] IPCP: Close event Nov 5 20:26:59 ppp [opt2] Bundle: Status update: up 0 links, total bandwidth 9600 bps Nov 5 20:26:59 ppp [opt2_link0] Link: Leave bundle "opt2" Nov 5 20:26:59 ppp [opt2_link0] LCP: state change Opened --> Starting Nov 5 20:26:59 ppp [opt2_link0] LCP: Down event Nov 5 20:26:59 ppp [opt2_link0] Link: DOWN event Nov 5 20:26:59 ppp [opt2_link0] can't remove hook mpd32964-0 from node "[630]:": No such file or directory Nov 5 20:26:59 ppp [opt2_link0] PPPoE: connection closed Nov 5 20:26:59 ppp [opt1] IPCP: LayerDown Nov 5 20:26:59 ppp [opt1] IPCP: SendTerminateReq #4 Nov 5 20:26:59 ppp [opt1] IPCP: state change Opened --> Closing Nov 5 20:26:59 ppp [opt1] IPCP: Close event Nov 5 20:26:59 ppp [opt1] Bundle: Status update: up 0 links, total bandwidth 9600 bps Nov 5 20:26:59 ppp [opt1_link0] Link: Leave bundle "opt1" Nov 5 20:26:59 ppp [opt1_link0] LCP: state change Opened --> Starting Nov 5 20:26:59 ppp [opt1_link0] LCP: Down event Nov 5 20:26:59 kernel vlan2: changing name to 'igb4.7' Nov 5 20:26:59 ppp [opt1_link0] Link: DOWN event Nov 5 20:26:59 ppp [opt1_link0] can't remove hook mpd92160-0 from node "[620]:": No such file or directory Nov 5 20:26:59 ppp [opt1_link0] PPPoE: connection closed Nov 5 20:26:59 check_reload_status updating dyndns opt14 Nov 5 20:26:57 check_reload_status Restarting ipsec tunnels Nov 5 20:26:56 kernel vlan1: changing name to 'igb2.3001' Nov 5 20:26:56 check_reload_status updating dyndns opt13 Nov 5 20:26:54 check_reload_status Restarting ipsec tunnels Nov 5 20:26:54 kernel vlan0: changing name to 'igb2.3000' Nov 5 20:26:54 check_reload_status updating dyndns opt11 Nov 5 20:26:52 check_reload_status Restarting ipsec tunnels Nov 5 20:26:50 check_reload_status Syncing firewall
Updated by Grischa Zengel about 4 years ago
Is this the problem?
kernel vlan2: changing name to 'igb4.7'
Updated by Viktor Gurov about 4 years ago
Updated by Viktor Gurov about 4 years ago
partially fixed in #9154 - on 2.5 I can get this error only when MTU is changed
Updated by Viktor Gurov about 4 years ago
Set child interfaces MTU fix:
https://gitlab.netgate.com/pfSense/pfSense/-/merge_requests/41
Updated by Jim Pingle about 4 years ago
- Status changed from New to Pull Request Review
- Priority changed from Very High to Normal
Updated by Renato Botelho about 4 years ago
- Status changed from Pull Request Review to Feedback
- Assignee set to Viktor Gurov
PR has been merged. Thanks!
Updated by Viktor Gurov about 4 years ago
- Status changed from Feedback to Resolved
works as expected on 2.5.0.a.20201130.0650 -
now it restarts child PPP* interface when MTU changes