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 5 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 5 years ago
Is this the problem?
kernel vlan2: changing name to 'igb4.7'
Updated by Viktor Gurov about 5 years ago
Updated by Viktor Gurov about 5 years ago
partially fixed in #9154 - on 2.5 I can get this error only when MTU is changed
Updated by Viktor Gurov about 5 years ago
Set child interfaces MTU fix:
https://gitlab.netgate.com/pfSense/pfSense/-/merge_requests/41
Updated by Jim Pingle about 5 years ago
- Status changed from New to Pull Request Review
- Priority changed from Very High to Normal
Updated by Renato Botelho about 5 years ago
- Status changed from Pull Request Review to Feedback
- Assignee set to Viktor Gurov
PR has been merged. Thanks!
Updated by Viktor Gurov almost 5 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