Project

General

Profile

Actions

Bug #11035

closed

PPPoE: can't remove hook

Added by Grischa Zengel 12 months ago. Updated 11 months ago.

Status:
Resolved
Priority:
Normal
Assignee:
Category:
PPP Interfaces
Target version:
Start date:
11/05/2020
Due date:
% Done:

0%

Estimated time:
Plus Target Version:
Release Notes:
Affected Version:
2.4.5-p1
Affected Architecture:

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
Actions #1

Updated by Grischa Zengel 12 months 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 
Actions #2

Updated by Grischa Zengel 12 months ago

Is this the problem?

kernel vlan2: changing name to 'igb4.7'

Actions #4

Updated by Viktor Gurov 12 months ago

partially fixed in #9154 - on 2.5 I can get this error only when MTU is changed

Actions #6

Updated by Viktor Gurov 12 months ago

  • Target version set to 2.5.0
Actions #7

Updated by Jim Pingle 11 months ago

  • Status changed from New to Pull Request Review
  • Priority changed from Very High to Normal
Actions #8

Updated by Renato Botelho 11 months ago

  • Status changed from Pull Request Review to Feedback
  • Assignee set to Viktor Gurov

PR has been merged. Thanks!

Actions #9

Updated by Viktor Gurov 11 months 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

Actions

Also available in: Atom PDF