gif0 does not come up after reboot
-
Hi everyone!
I switched from having my OpenWRT router setting up the PPPoE connection to my internet provider to having a pfSense virtual machine doing so.
As my provider is using Dual-Stack Lite I need to set up a tunnel interface gif0 that tunnels all IPv4 packets through the IPv6 connection. The gif0 tunnel I am using for this is linked to interface 4IN6.
The tunnel is working fine if I manually open the 4IN6 interface in the GUI, change nothing and click "Save" and "Apply changes". But it is not working after a reboot of the VM.
This looks like some interface dependency to me. Does anybody know how I can get this issue solved?
I am using pfSense 2.6.0-RELEASE (amd64).
Regards
-
Can we see how it's configured?
Do you see anything the logs at boot showing it fail to connect? Any other errors?
Steve
-
Hi!
I've looked into the logs and this is what comes up during boot:
Oct 19 07:48:27 php 458 rc.bootup: The command '/sbin/ifconfig 'gif0' description '4IN6'' returned exit code '1', the output was 'ifconfig: interface gif0 does not exist'
When I go into the interface after the boot process and save and apply changes, the interface comes up:
Oct 19 07:53:10 kernel gif0: link state changed to UP
This is the current configuration I have on that interface:
Kind regards
-
This looks strange (to me) :
and
A GIF tunnels IPv6 over a IPv4 link.
The GIF Remote address should be IPv4 - not IPv6.
A tunnel can't have a IPv4 on one side, and a IPv6 on the other ....Or are you tunnelling IPv4 over a IPv6 ?
-
@gertjan Yes, I am tunneling IPv4 over the IPv6 link. If I don‘t use the gif0 tunnel, the IPv4 internet is non-existent for me, but IPv6 works fine.
-
Then check the subnet, you've set "29"
Or, if you use an IPv4 as tunnel local and remote address being IPv4, the "25" is strange.
It could be 24 at max.Something like 192.0.0.1/29 is weird.
edit : more weird, but something of the future ; you have an IPv6, and need to use GIF to get : an IPv4 .... so, right now, if that doesn't work, you only have IPv6 an no IPv4 : isn't 75 % of "all internet" now inaccessible to you ? More ? Less ?
-
@gertjan What I do seems to be standard for Dual-Stack-Lite setups RFC8585. This tunnels IPv4 packets in an IPv6 connection to an CG-NAT or AFTR element, which in turn unpacks the precious IPv4 contents.
The tunneling addresses and netmasks are defined in RFC6333.
My AFTR address is equal to the GIF Remote Address.
As I've mentioned earlier in my post: everything is working perfectly after I a click into the gif0 Interface, click "Save" and "Apply changes" (although I haven't changed anything in the interface). My only problem is that the connection does not come up automatically after a reboot of pfSense.
-
@vex said in gif0 does not come up after reboot:
The tunneling addresses and netmasks are defined in RFC6333.
Saw that :
I guess I'm learning something new here.
@vex said in gif0 does not come up after reboot:
working perfectly after
Like : I'm thinking out loud :
The GIF tunnel is started before the pppoe connections comes up.
So it fails.
When you re apply the GIF, it works, as your pppoe connection is up now.Did you look at the logs - the main system log but also the others, where the pppoe connections creation is logged ? And if there are traces of the GIF being created and fails ?
And when is what created ? The chronology of the events.
And where it manages to connect ? -
Is your LAN set to track WAN for it's IPv6 prefix?
If so that might explain it. The PPPoE link will not come up immediately.
Why are you using LAN there and not WAN as the parent interface?
Steve
-
I wanted and I tried to set WAN as parent because it’s only logical, but that‘s barking at me with an error (creating interface). I can only set a LAN as parent during creation. But yeah, that‘s explaining the issue. Changing the parent after creating the gif is also not possible.
-
Mmm, appears to be the rather unhelpful:
The following input errors were detected: Error occurred creating interface, please retry.
Let me test....
-
@stephenw10 Exactly this error.. :)
-
Ok, that error is shown if the PPPoE interface is not up at the time. It wasn't on my test box. But I can create a GIF tunnel on a PPPoE interface as long as it's connected and has an IP at that time. And it does then re-establish at boot.
However I tested here with IPv4, it's possible it will refuse to allow a tunnel with a remote IPv6 address even if the PPPoE interface has one. I assume that's the situation you're in?
It's possible your ISP only provides a prefix and the WAN doesn't get a routable v6 IP.Also I'm testing between local machines which mean the PPP connection estblishes almost instantly at boot so it's possible there is a timing issue. I don't think that is the case though because the GIF tunnel doesn't attempt to establish until the PPPoE is up because it's parent interface is down. The way you have it setup LAN appears to be up to it tries and fails.
What does appear to be a possible bug is that the LAN interface gets a new IP address when the PPPoE comes up and it can track the prefix. But that doesn't trigger the GIF tunnel to restart.
However there are a number of features missing from dynamic IPv6. This is probably one of them.Anyway I would retry to create the GIF on WAN directly. At least that might give us a different error. I can't easily test an IPv6 PPPoE connection here.
Steve
-
@stephenw10 Hi Stephen, you're right. The PPPoE interface does not get a routeable address. ifconfig shows:
[2.6.0-RELEASE][admin@pfSense.lan]/root: ifconfig vtnet0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500 description: LAN options=800b8<VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,LINKSTATE> ether 92:5d:58:1f:81:ff inet6 fe80::905d:58ff:fe1f:81ff%vtnet0 prefixlen 64 scopeid 0x1 inet6 fe80::1:1%vtnet0 prefixlen 64 duplicated scopeid 0x1 inet6 2001:a62:5a5:5400:905d:58ff:fe1f:81ff prefixlen 64 inet 10.100.198.2 netmask 0xffffff00 broadcast 10.100.198.255 media: Ethernet 10Gbase-T <full-duplex> status: active nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL> vtnet1: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500 options=800b8<VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,LINKSTATE> ether 46:24:0c:f0:9e:d1 inet6 fe80::4424:cff:fef0:9ed1%vtnet1 prefixlen 64 scopeid 0x2 media: Ethernet 10Gbase-T <full-duplex> status: active nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL> vtnet2: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500 description: LAN2 options=800b8<VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,LINKSTATE> ether 06:76:15:c6:76:8b inet6 fe80::476:15ff:fec6:768b%vtnet2 prefixlen 64 scopeid 0x3 inet6 fe80::1:1%vtnet2 prefixlen 64 scopeid 0x3 inet6 2001:a62:5a5:5401:476:15ff:fec6:768b prefixlen 64 inet 10.100.100.1 netmask 0xffffff00 broadcast 10.100.100.255 media: Ethernet 10Gbase-T <full-duplex> status: active nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL> enc0: flags=0<> metric 0 mtu 1536 groups: enc nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL> lo0: flags=8049<UP,LOOPBACK,RUNNING,MULTICAST> metric 0 mtu 16384 options=680003<RXCSUM,TXCSUM,LINKSTATE,RXCSUM_IPV6,TXCSUM_IPV6> inet6 ::1 prefixlen 128 inet6 fe80::1%lo0 prefixlen 64 scopeid 0x5 inet 127.0.0.1 netmask 0xff000000 groups: lo nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL> pflog0: flags=100<PROMISC> metric 0 mtu 33160 groups: pflog pfsync0: flags=0<> metric 0 mtu 1500 groups: pfsync pppoe0: flags=88d1<UP,POINTOPOINT,RUNNING,NOARP,SIMPLEX,MULTICAST> metric 0 mtu 1492 description: WAN inet6 fe80::905d:58ff:fe1f:81ff%pppoe0 prefixlen 64 scopeid 0x8 nd6 options=23<PERFORMNUD,ACCEPT_RTADV,AUTO_LINKLOCAL> gif0: flags=8051<UP,POINTOPOINT,RUNNING,MULTICAST> metric 0 mtu 1280 description: 4IN6 options=80000<LINKSTATE> tunnel inet6 2001:a62:5a5:5400:905d:58ff:fe1f:81ff --> 2001:a60:0:1::ffff inet 192.0.0.2 --> 192.0.0.1 netmask 0xfffffff8 inet6 fe80::8c91:4795:5f5f:cd3e%gif0 prefixlen 64 scopeid 0x9 groups: gif nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL>
I did try to set up new gif interfaces to no avail. Getting the same error as you all over again. Thank you for diving into this and helping me. This is very much appreciated.
Regards
Alex -
@stephenw10 I managed to create a second gif while the first one was still down. Setting the parent interface to WAN worked this way.
Unfortunately, the interface still doesn't come up during boot and even more unfortunate is that the IPv4 routing does not work if I use WAN as parent interface. It shows as up, but the tunnel does not work.dmesg shows
lo0: link state changed to UP vtnet0: link state changed to UP vtnet2: link state changed to UP vtnet1: link state changed to UP ng0: changing name to 'pppoe0' vtnet0: DAD detected duplicate IPv6 address fe80:1::1:1: NS in/out/loopback=1/1/0, NA in=0 vtnet0: DAD complete for fe80:1::1:1 - duplicate found vtnet0: manual intervention required ng_pppoe[12]: no matching session pflog0: promiscuous mode enabled
and ifconfig
[2.6.0-RELEASE][admin@pfSense.lan]/root: ifconfig vtnet0: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500 description: LAN options=800b8<VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,LINKSTATE> ether 92:5d:58:1f:81:ff inet6 fe80::905d:58ff:fe1f:81ff%vtnet0 prefixlen 64 scopeid 0x1 inet6 fe80::1:1%vtnet0 prefixlen 64 duplicated scopeid 0x1 inet6 2001:a62:5a5:a400:905d:58ff:fe1f:81ff prefixlen 64 inet 10.100.198.2 netmask 0xffffff00 broadcast 10.100.198.255 media: Ethernet 10Gbase-T <full-duplex> status: active nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL> vtnet1: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500 options=800b8<VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,LINKSTATE> ether 46:24:0c:f0:9e:d1 inet6 fe80::4424:cff:fef0:9ed1%vtnet1 prefixlen 64 scopeid 0x2 media: Ethernet 10Gbase-T <full-duplex> status: active nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL> vtnet2: flags=8843<UP,BROADCAST,RUNNING,SIMPLEX,MULTICAST> metric 0 mtu 1500 description: LAN2 options=800b8<VLAN_MTU,VLAN_HWTAGGING,JUMBO_MTU,VLAN_HWCSUM,LINKSTATE> ether 06:76:15:c6:76:8b inet6 fe80::476:15ff:fec6:768b%vtnet2 prefixlen 64 scopeid 0x3 inet6 fe80::1:1%vtnet2 prefixlen 64 scopeid 0x3 inet6 2001:a62:5a5:a401:476:15ff:fec6:768b prefixlen 64 inet 10.100.100.1 netmask 0xffffff00 broadcast 10.100.100.255 media: Ethernet 10Gbase-T <full-duplex> status: active nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL> enc0: flags=0<> metric 0 mtu 1536 groups: enc nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL> lo0: flags=8049<UP,LOOPBACK,RUNNING,MULTICAST> metric 0 mtu 16384 options=680003<RXCSUM,TXCSUM,LINKSTATE,RXCSUM_IPV6,TXCSUM_IPV6> inet6 ::1 prefixlen 128 inet6 fe80::1%lo0 prefixlen 64 scopeid 0x5 inet 127.0.0.1 netmask 0xff000000 groups: lo nd6 options=21<PERFORMNUD,AUTO_LINKLOCAL> pflog0: flags=100<PROMISC> metric 0 mtu 33160 groups: pflog pfsync0: flags=0<> metric 0 mtu 1500 groups: pfsync pppoe0: flags=88d1<UP,POINTOPOINT,RUNNING,NOARP,SIMPLEX,MULTICAST> metric 0 mtu 1492 description: WAN inet6 fe80::905d:58ff:fe1f:81ff%pppoe0 prefixlen 64 scopeid 0x8 nd6 options=23<PERFORMNUD,ACCEPT_RTADV,AUTO_LINKLOCAL>
Don't know where to find logs of gif creation at boot time.
-
If you have just rebooted it should be in the main system log when it tries to bring up the tunnel.
Does that new tunnel come up if you restart after booting? Despite having no routable IPv6 address on WAN?
Do the PPP logs look like it's trying to pass a v6 IP to the WAN as well as a prefix?
Steve
-
Hi Stephen,
the following is a log excerpt that I am getting after a reboot:
Oct 22 20:20:19 check_reload_status 442 Syncing firewall Oct 22 20:20:19 php-fpm 414 /interfaces.php: Configuration Change: admin@2001:a62:5ae:de00:cddc:d09:b164:5252 (Local Database): Interfaces settings changed Oct 22 20:20:15 php-fpm 414 /index.php: Successful login for user 'admin' from: 2001:a62:5ae:de00:cddc:d09:b164:5252 (Local Database) Oct 22 20:19:59 sshguard 9283 Now monitoring attacks. Oct 22 20:19:59 login 7620 login on ttyv0 as root Oct 22 20:19:57 root 76381 Bootup complete Oct 22 20:19:57 php-fpm 414 /rc.start_packages: Restarting/Starting all packages. Oct 22 20:19:57 kernel done. Oct 22 20:19:57 syslogd kernel boot file is /boot/kernel/kernel Oct 22 20:19:56 syslogd exiting on signal 15 Oct 22 20:19:56 kernel done. Oct 22 20:19:56 php 458 rc.bootup: Creating rrd update script Oct 22 20:19:52 kernel .....done. Oct 22 20:19:52 php 458 rc.bootup: The command '/usr/local/sbin/strongswanrc stop' returned exit code '1', the output was 'strongswan not running? (check /var/run/daemon-charon.pid).' Oct 22 20:19:52 check_reload_status 442 Updating all dyndns Oct 22 20:19:52 kernel done. Oct 22 20:19:52 kernel done. Oct 22 20:19:51 kernel done. Oct 22 20:19:51 kernel done. Oct 22 20:19:50 php 458 rc.bootup: NTPD is starting up. Oct 22 20:19:50 kernel done. Oct 22 20:19:50 php 458 rc.bootup: The command '/usr/bin/timeout -k 45 30 /usr/local/sbin/ntpd -g -q -c /dev/null 216.239.35.0 216.239.35.4 216.239.35.8 216.239.35.12' returned exit code '124', the output was '22 Oct 20:19:20 ntpd[96989]: ntpd 4.2.8p15@1.3728-o Wed Jan 12 15:39:52 UTC 2022 (1): Starting 22 Oct 20:19:20 ntpd[96989]: Command line: /usr/local/sbin/ntpd -g -q -c /dev/null 216.239.35.0 216.239.35.4 216.239.35.8 216.239.35.12 22 Oct 20:19:20 ntpd[96989]: ---------------------------------------------------- 22 Oct 20:19:20 ntpd[96989]: ntp-4 is maintained by Network Time Foundation, 22 Oct 20:19:20 ntpd[96989]: Inc. (NTF), a non-profit 501(c)(3) public-benefit 22 Oct 20:19:20 ntpd[96989]: corporation. Support and training for ntp-4 are 22 Oct 20:19:20 ntpd[96989]: available at https://www.nwtime.org/support 22 Oct 20:19:20 ntpd[96989]: ---------------------------------------------------- 22 Oct 20:19:20 ntpd[96989]: proto: precision = 0.121 usec (-23) 22 Oct 20:19:20 ntpd[96989]: line 0 column 0 syntax error, unexpected $end 22 Oct 20:19:20 ntpd[96989]: basedate set to 2021-12-31 22 Oct 20:19:20 ntpd[96989]: gps base set to 2022-01-02 (week 2191) 22 Oct 20:19:20 ntpd[96989]: Listen and drop on 0 v6wildcard [::]:123 22 Oct 20:19:20 ntpd[96989]: Listen and drop on 1 v4wildcard 0.0.0.0:123 22 Oct 20:19:20 ntpd[96989]: Listen normally on 2 vtnet0 [fe80::905d:58ff:fe1f:81ff%1]:123 22 Oct 20:19:20 ntpd[96989]: Listen normally on 3 vtnet0 10.100.198.2:123 22 Oct 20:19:20 ntpd[96989]: Listen normally on 4 vtnet0 [fe80::1:1%1]:123 22 Oct 20:19:20 ntpd[96989]: Listen normally on 5 vtnet0 [2001:a62:5ae:de00:905d:58ff:fe1f:81ff]:123 22 Oct 20:19:20 ntpd[96989]: Listen normally on 6 vtnet1 [fe80::4424:cff:fef0:9ed1%2]:123 22 Oct 20:19:20 ntpd[96989]: Listen normally on 7 vtnet2 [fe80::476:15ff:fec6:768b%3]:123 22 Oct 20:19:20 ntpd[96989]: Listen normally on 8 lo0 [::1]:123 22 Oct 20:19:20 ntpd[96989]: Listen normally on 9 lo0 [fe80::1%5]:123 22 Oct 20:19:20 ntpd[96989]: Listen Oct 22 20:19:20 kernel done. Oct 22 20:19:20 kernel done. Oct 22 20:19:20 php 458 rc.bootup: sync unbound done. Oct 22 20:19:19 php-fpm 413 /rc.newwanipv6: Gateway, NONE AVAILABLE Oct 22 20:19:18 php 458 rc.bootup: dhcp6 init complete. Continuing Oct 22 20:19:18 php-fpm 414 /rc.newwanipv6: Gateway, NONE AVAILABLE Oct 22 20:19:18 php-fpm 414 /rc.newwanipv6: dpinger: status socket /var/run/dpinger_WAN_DHCP6~fe80::905d:58ff:fe1f:81ff%pppoe0~fe80::2cc:34ff:fe44:b067%pppoe0.sock not found Oct 22 20:19:18 php-fpm 413 /rc.newwanipv6: rc.newwanipv6: on (IP address: fe80::905d:58ff:fe1f:81ff%pppoe0) (interface: wan) (real interface: pppoe0). Oct 22 20:19:18 php-fpm 413 /rc.newwanipv6: rc.newwanipv6: Info: starting on pppoe0. Oct 22 20:19:18 php-fpm 414 /rc.newwanipv6: rc.newwanipv6: on (IP address: fe80::905d:58ff:fe1f:81ff%pppoe0) (interface: wan) (real interface: pppoe0). Oct 22 20:19:18 php-fpm 414 /rc.newwanipv6: rc.newwanipv6: Info: starting on pppoe0. Oct 22 20:19:17 kernel done. Oct 22 20:19:17 php 458 rc.bootup: Unbound start waiting on dhcp6c. Oct 22 20:19:17 php 458 rc.bootup: Gateway, NONE AVAILABLE Oct 22 20:19:17 ppp 10808 [wan] IFACE: Add description "WAN" Oct 22 20:19:17 ppp 10808 [wan] IFACE: Rename interface ng0 to pppoe0 Oct 22 20:19:17 ppp 10808 [wan] IFACE: Up event Oct 22 20:19:17 check_reload_status 442 rc.newwanipv6 starting pppoe0 Oct 22 20:19:16 kernel pflog0: promiscuous mode enabled Oct 22 20:19:16 kernel done. Oct 22 20:19:16 php 458 rc.bootup: Resyncing OpenVPN instances. Oct 22 20:19:16 php 458 rc.bootup: calling interface_dhcpv6_configure. Oct 22 20:19:16 rtsold 17891 Starting dhcp6 client for interface wan(pppoe0) Oct 22 20:19:16 rtsold 17366 Received RA specifying route fe80::2cc:34ff:fe44:b067 for interface wan(pppoe0) Oct 22 20:19:16 check_reload_status 442 Rewriting resolv.conf Oct 22 20:19:16 kernel ng_pppoe[12]: no matching session Oct 22 20:19:14 sshguard 13592 Now monitoring attacks. Oct 22 20:19:14 sshd 12982 Server listening on 0.0.0.0 port 22. Oct 22 20:19:14 sshd 12982 Server listening on :: port 22. Oct 22 20:19:14 php 11645 /usr/local/sbin/ppp-ipv6: Starting rtsold process Oct 22 20:19:14 php 11645 /usr/local/sbin/ppp-ipv6: Accept router advertisements on interface pppoe0 Oct 22 20:19:14 ppp 10808 [wan] 905d:58ff:fe1f:81ff -> 02cc:34ff:fe44:b067 Oct 22 20:19:14 ppp 10808 [wan] IPV6CP: LayerUp Oct 22 20:19:14 ppp 10808 [wan] IPV6CP: state change Ack-Sent --> Opened Oct 22 20:19:14 ppp 10808 [wan] IPV6CP: rec'd Configure Ack #1 (Ack-Sent) Oct 22 20:19:14 ppp 10808 [wan] IPV6CP: state change Req-Sent --> Ack-Sent Oct 22 20:19:14 ppp 10808 [wan] IPV6CP: SendConfigAck #218 Oct 22 20:19:14 ppp 10808 [wan] IPV6CP: rec'd Configure Request #218 (Req-Sent) Oct 22 20:19:14 ppp 10808 [wan] IPCP: LayerFinish Oct 22 20:19:14 ppp 10808 [wan] IPCP: state change Req-Sent --> Stopped Oct 22 20:19:14 ppp 10808 [wan] IPCP: protocol was rejected by peer Oct 22 20:19:14 ppp 10808 [wan_link0] LCP: protocol IPCP was rejected Oct 22 20:19:14 ppp 10808 [wan_link0] LCP: rec'd Protocol Reject #12 (Opened) Oct 22 20:19:14 ppp 10808 [wan] IPV6CP: SendConfigReq #1 Oct 22 20:19:14 ppp 10808 [wan] IPV6CP: state change Starting --> Req-Sent Oct 22 20:19:14 ppp 10808 [wan] IPV6CP: Up event Oct 22 20:19:14 ppp 10808 [wan] SECDNS 0.0.0.0 Oct 22 20:19:14 ppp 10808 [wan] PRIDNS 0.0.0.0 Oct 22 20:19:14 ppp 10808 [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Oct 22 20:19:14 ppp 10808 [wan] IPADDR 0.0.0.0 Oct 22 20:19:14 ppp 10808 [wan] IPCP: SendConfigReq #1 Oct 22 20:19:14 ppp 10808 [wan] IPCP: state change Starting --> Req-Sent Oct 22 20:19:14 ppp 10808 [wan] IPCP: Up event Oct 22 20:19:14 ppp 10808 [wan] IPV6CP: LayerStart Oct 22 20:19:14 ppp 10808 [wan] IPV6CP: state change Initial --> Starting Oct 22 20:19:14 ppp 10808 [wan] IPV6CP: Open event Oct 22 20:19:14 ppp 10808 [wan] IPCP: LayerStart Oct 22 20:19:14 ppp 10808 [wan] IPCP: state change Initial --> Starting Oct 22 20:19:14 ppp 10808 [wan] IPCP: Open event Oct 22 20:19:14 ppp 10808 [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps Oct 22 20:19:14 ppp 10808 [wan_link0] Link: Join bundle "wan" Oct 22 20:19:14 ppp 10808 [wan_link0] Link: Matched action 'bundle "wan" ""' Oct 22 20:19:14 ppp 10808 [wan_link0] LCP: authorization successful Oct 22 20:19:14 ppp 10808 [wan_link0] CHAP: rec'd SUCCESS #114 len: 4 Oct 22 20:19:13 ppp 10808 [wan_link0] CHAP: sending RESPONSE #114 len: 51 Oct 22 20:19:13 ppp 10808 [wan_link0] CHAP: Using authname "XXXXXXXXXXXX@mdsl.mnet-online.de" Oct 22 20:19:13 ppp 10808 [wan_link0] Name: "ac3.nue2" Oct 22 20:19:13 ppp 10808 [wan_link0] CHAP: rec'd CHALLENGE #114 len: 36 Oct 22 20:19:13 ppp 10808 [wan_link0] LCP: LayerUp Oct 22 20:19:13 ppp 10808 [wan_link0] LCP: auth: peer wants CHAP, I want nothing Oct 22 20:19:13 ppp 10808 [wan_link0] LCP: state change Ack-Sent --> Opened Oct 22 20:19:13 ppp 10808 [wan_link0] MAGICNUM 0xd716b7a0 Oct 22 20:19:13 ppp 10808 [wan_link0] MRU 1492 Oct 22 20:19:13 ppp 10808 [wan_link0] PROTOCOMP Oct 22 20:19:13 ppp 10808 [wan_link0] LCP: rec'd Configure Ack #1 (Ack-Sent) Oct 22 20:19:13 ppp 10808 [wan_link0] LCP: state change Req-Sent --> Ack-Sent Oct 22 20:19:13 ppp 10808 [wan_link0] MAGICNUM 0x7162e1bf Oct 22 20:19:13 ppp 10808 [wan_link0] AUTHPROTO CHAP MD5 Oct 22 20:19:13 ppp 10808 [wan_link0] MRU 1492 Oct 22 20:19:13 ppp 10808 [wan_link0] LCP: SendConfigAck #11 Oct 22 20:19:13 ppp 10808 [wan_link0] MAGICNUM 0x7162e1bf Oct 22 20:19:13 ppp 10808 [wan_link0] AUTHPROTO CHAP MD5 Oct 22 20:19:13 ppp 10808 [wan_link0] MRU 1492 Oct 22 20:19:13 ppp 10808 [wan_link0] LCP: rec'd Configure Request #11 (Req-Sent) Oct 22 20:19:13 ppp 10808 [wan_link0] MAGICNUM 0xd716b7a0 Oct 22 20:19:13 ppp 10808 [wan_link0] MRU 1492 Oct 22 20:19:13 ppp 10808 [wan_link0] PROTOCOMP Oct 22 20:19:13 ppp 10808 [wan_link0] LCP: SendConfigReq #1 Oct 22 20:19:13 ppp 10808 [wan_link0] LCP: state change Starting --> Req-Sent Oct 22 20:19:13 ppp 10808 [wan_link0] LCP: Up event Oct 22 20:19:13 ppp 10808 [wan_link0] Link: UP event Oct 22 20:19:13 ppp 10808 [wan_link0] PPPoE: connection successful Oct 22 20:19:13 ppp 10808 PPPoE: rec'd ACNAME "ac3.nue2" Oct 22 20:19:13 ppp 10808 [wan_link0] PPPoE: Connecting to '' Oct 22 20:19:13 ppp 10808 [wan_link0] LCP: LayerStart Oct 22 20:19:13 ppp 10808 [wan_link0] LCP: state change Initial --> Starting Oct 22 20:19:13 ppp 10808 [wan_link0] LCP: Open event Oct 22 20:19:13 kernel ng0: changing name to 'pppoe0' Oct 22 20:19:13 ppp 10808 [wan_link0] Link: OPEN event Oct 22 20:19:13 ppp 10808 [wan] Bundle: Interface ng0 created Oct 22 20:19:13 ppp 10808 web: web is not running Oct 22 20:19:13 ppp 10808 process 10808 started, version 5.9 Oct 22 20:19:13 ppp 10808 Multi-link PPP daemon for FreeBSD Oct 22 20:19:13 kernel vtnet2: link state changed to UP Oct 22 20:19:13 check_reload_status 442 Linkup starting vtnet2 Oct 22 20:19:13 kernel vtnet1: link state changed to UP Oct 22 20:19:13 kernel done. Oct 22 20:19:13 check_reload_status 442 Linkup starting vtnet1 Oct 22 20:19:13 php 458 rc.bootup: The command '/sbin/ifconfig 'gif0' description '4IN6'' returned exit code '1', the output was 'ifconfig: interface gif0 does not exist' Oct 22 20:19:13 kernel vtnet0: link state changed to UP Oct 22 20:19:13 check_reload_status 442 Linkup starting vtnet0 Oct 22 20:19:13 kernel lo0: link state changed to UP
4IN6 (gif0) tunnel does not come up with the reboot. If I now manually do the "Save"/"Apply changes"-Wizardry, the gif0 comes up and the logs show:
Oct 22 20:26:43 check_reload_status 442 Reloading filter Oct 22 20:26:43 check_reload_status 442 Restarting OpenVPN tunnels/interfaces Oct 22 20:26:43 check_reload_status 442 Restarting IPsec tunnels Oct 22 20:26:43 check_reload_status 442 updating dyndns 4IN6_TUNNELV4 Oct 22 20:26:43 rc.gateway_alarm 78678 >>> Gateway alarm: 4IN6_TUNNELV4 (Addr:192.0.0.1 Alarm:1 RTT:0.000ms RTTsd:0.000ms Loss:100%) Oct 22 20:26:41 php-fpm 414 /interfaces.php: Creating rrd update script Oct 22 20:26:41 check_reload_status 442 Reloading filter Oct 22 20:26:39 check_reload_status 442 updating dyndns opt1 Oct 22 20:26:36 dhcpleases 64283 Could not deliver signal HUP to process 90863: No such process. Oct 22 20:26:35 check_reload_status 442 Restarting IPsec tunnels Oct 22 20:26:35 kernel gif0: link state changed to UP Oct 22 20:26:35 php-fpm 414 /interfaces.php: Default gateway setting Interface 4IN6_TUNNELV4 Gateway as default.
What I find slightly interesting, is that the IPv4 tunnel gateway has 100% packet loss in the gateway monitor, although it works flawlessly.
Kind regards
Alex -
@vex said in gif0 does not come up after reboot:
Oct 22 20:19:13 php 458 rc.bootup: The command '/sbin/ifconfig 'gif0' description '4IN6'' returned exit code '1', the output was 'ifconfig: interface gif0 does not exist'
Oct 22 20:19:13 kernel vtnet0: link state changed to UPThat's with the gif tunnel using WAN as the parent? Or LAN still?
Is the PPPoE interface first in the list?
I note that you appear to have WAN set to dhcpv6 but the PPPoE is passing an IPv6 address via IPV6CP directly.
The IPv4 gateway may simply not respond to ping. Try setting a monitoring IP somewhere further upstream like 8.8.8.8.
Steve
-
That's with the gif0 using LAN as parent. PPPoE is first in list, yes.
So instead of using DHCPv6 as configuration type, should I use something else there?
Yeah, I switched to monitoring the IPv6 CG-NAT/AFTR address.
This is the complete log of booting with gif0 and WAN as parent:
Oct 26 21:45:42 php-fpm 366 /index.php: Successful login for user 'admin' from: 10.100.198.249 (Local Database) Oct 26 21:45:37 sshguard 61915 Now monitoring attacks. Oct 26 21:45:37 login 59892 login on ttyv0 as root Oct 26 21:45:36 root 51758 Bootup complete Oct 26 21:45:35 php-fpm 366 /rc.start_packages: Restarting/Starting all packages. Oct 26 21:45:35 kernel done. Oct 26 21:45:35 syslogd kernel boot file is /boot/kernel/kernel Oct 26 21:45:35 syslogd exiting on signal 15 Oct 26 21:45:35 php 411 rc.bootup: Creating rrd update script Oct 26 21:45:31 kernel .....done. Oct 26 21:45:31 php 411 rc.bootup: The command '/usr/local/sbin/strongswanrc stop' returned exit code '1', the output was 'strongswan not running? (check /var/run/daemon-charon.pid).' Oct 26 21:45:30 check_reload_status 395 Updating all dyndns Oct 26 21:45:30 kernel done. Oct 26 21:45:30 kernel done. Oct 26 21:45:30 kernel done. Oct 26 21:45:29 kernel done. Oct 26 21:45:29 php 411 rc.bootup: NTPD is starting up. Oct 26 21:45:29 kernel done. Oct 26 21:45:29 php 411 rc.bootup: The command '/usr/bin/timeout -k 45 30 /usr/local/sbin/ntpd -g -q -c /dev/null 216.239.35.0 216.239.35.4 216.239.35.8 216.239.35.12' returned exit code '124', the output was '26 Oct 21:44:59 ntpd[75103]: ntpd 4.2.8p15@1.3728-o Wed Jan 12 15:39:52 UTC 2022 (1): Starting 26 Oct 21:44:59 ntpd[75103]: Command line: /usr/local/sbin/ntpd -g -q -c /dev/null 216.239.35.0 216.239.35.4 216.239.35.8 216.239.35.12 26 Oct 21:44:59 ntpd[75103]: ---------------------------------------------------- 26 Oct 21:44:59 ntpd[75103]: ntp-4 is maintained by Network Time Foundation, 26 Oct 21:44:59 ntpd[75103]: Inc. (NTF), a non-profit 501(c)(3) public-benefit 26 Oct 21:44:59 ntpd[75103]: corporation. Support and training for ntp-4 are 26 Oct 21:44:59 ntpd[75103]: available at https://www.nwtime.org/support 26 Oct 21:44:59 ntpd[75103]: ---------------------------------------------------- 26 Oct 21:44:59 ntpd[75103]: proto: precision = 0.123 usec (-23) 26 Oct 21:44:59 ntpd[75103]: line 0 column 0 syntax error, unexpected $end 26 Oct 21:44:59 ntpd[75103]: basedate set to 2021-12-31 26 Oct 21:44:59 ntpd[75103]: gps base set to 2022-01-02 (week 2191) 26 Oct 21:44:59 ntpd[75103]: Listen and drop on 0 v6wildcard [::]:123 26 Oct 21:44:59 ntpd[75103]: Listen and drop on 1 v4wildcard 0.0.0.0:123 26 Oct 21:44:59 ntpd[75103]: Listen normally on 2 vtnet0 [fe80::905d:58ff:fe1f:81ff%1]:123 26 Oct 21:44:59 ntpd[75103]: Listen normally on 3 vtnet0 10.100.198.2:123 26 Oct 21:44:59 ntpd[75103]: Listen normally on 4 vtnet0 [fe80::1:1%1]:123 26 Oct 21:44:59 ntpd[75103]: Listen normally on 5 vtnet0 [2001:a62:5d1:aa00:905d:58ff:fe1f:81ff]:123 26 Oct 21:44:59 ntpd[75103]: Listen normally on 6 vtnet1 [fe80::4424:cff:fef0:9ed1%2]:123 26 Oct 21:44:59 ntpd[75103]: Listen normally on 7 lo0 [::1]:123 26 Oct 21:44:59 ntpd[75103]: Listen normally on 8 lo0 [fe80::1%5]:123 26 Oct 21:44:59 ntpd[75103]: Listen normally on 9 lo0 127.0.0.1:123 26 Oct 21:44:59 ntpd[75103]: Listen normally on 10 pppoe0 Oct 26 21:44:59 kernel done. Oct 26 21:44:59 php 411 rc.bootup: sync unbound done. Oct 26 21:44:59 kernel done. Oct 26 21:44:57 php-fpm 367 /rc.newwanipv6: Gateway, NONE AVAILABLE Oct 26 21:44:57 php-fpm 367 /rc.newwanipv6: rc.newwanipv6: on (IP address: fe80::905d:58ff:fe1f:81ff%pppoe0) (interface: wan) (real interface: pppoe0). Oct 26 21:44:57 php-fpm 367 /rc.newwanipv6: rc.newwanipv6: Info: starting on pppoe0. Oct 26 21:44:57 php 411 rc.bootup: dhcp6 init complete. Continuing Oct 26 21:44:56 php-fpm 366 /rc.newwanipv6: Gateway, NONE AVAILABLE Oct 26 21:44:56 php-fpm 366 /rc.newwanipv6: rc.newwanipv6: on (IP address: fe80::905d:58ff:fe1f:81ff%pppoe0) (interface: wan) (real interface: pppoe0). Oct 26 21:44:56 php-fpm 366 /rc.newwanipv6: rc.newwanipv6: Info: starting on pppoe0. Oct 26 21:44:56 php 411 rc.bootup: Unbound start waiting on dhcp6c. Oct 26 21:44:55 ppp 9410 [wan] IFACE: Add description "WAN" Oct 26 21:44:55 ppp 9410 [wan] IFACE: Rename interface ng0 to pppoe0 Oct 26 21:44:55 ppp 9410 [wan] IFACE: Up event Oct 26 21:44:55 check_reload_status 395 rc.newwanipv6 starting pppoe0 Oct 26 21:44:55 rtsold 41957 Starting dhcp6 client for interface wan(pppoe0) Oct 26 21:44:55 rtsold 41008 Received RA specifying route fe80::2cc:34ff:fe44:b067 for interface wan(pppoe0) Oct 26 21:44:55 php 411 rc.bootup: Unbound start waiting on dhcp6c. Oct 26 21:44:55 kernel done. Oct 26 21:44:55 kernel pflog0: promiscuous mode enabled Oct 26 21:44:55 kernel done. Oct 26 21:44:55 php 411 rc.bootup: Gateway, NONE AVAILABLE Oct 26 21:44:55 php 411 rc.bootup: Resyncing OpenVPN instances. Oct 26 21:44:55 php 411 rc.bootup: calling interface_dhcpv6_configure. Oct 26 21:44:54 check_reload_status 395 Rewriting resolv.conf Oct 26 21:44:54 kernel ng_pppoe[12]: no matching session Oct 26 21:44:53 sshguard 12833 Now monitoring attacks. Oct 26 21:44:53 sshd 12231 Server listening on 0.0.0.0 port 22. Oct 26 21:44:53 sshd 12231 Server listening on :: port 22. Oct 26 21:44:52 php 10463 /usr/local/sbin/ppp-ipv6: Starting rtsold process Oct 26 21:44:52 php 10463 /usr/local/sbin/ppp-ipv6: Accept router advertisements on interface pppoe0 Oct 26 21:44:52 ppp 9410 [wan] 905d:58ff:fe1f:81ff -> 02cc:34ff:fe44:b067 Oct 26 21:44:52 ppp 9410 [wan] IPV6CP: LayerUp Oct 26 21:44:52 ppp 9410 [wan] IPV6CP: state change Ack-Sent --> Opened Oct 26 21:44:52 ppp 9410 [wan] IPV6CP: rec'd Configure Ack #1 (Ack-Sent) Oct 26 21:44:52 ppp 9410 [wan] IPV6CP: state change Req-Sent --> Ack-Sent Oct 26 21:44:52 ppp 9410 [wan] IPV6CP: SendConfigAck #120 Oct 26 21:44:52 ppp 9410 [wan] IPV6CP: rec'd Configure Request #120 (Req-Sent) Oct 26 21:44:52 ppp 9410 [wan] IPCP: LayerFinish Oct 26 21:44:52 ppp 9410 [wan] IPCP: state change Req-Sent --> Stopped Oct 26 21:44:52 ppp 9410 [wan] IPCP: protocol was rejected by peer Oct 26 21:44:52 ppp 9410 [wan_link0] LCP: protocol IPCP was rejected Oct 26 21:44:52 ppp 9410 [wan_link0] LCP: rec'd Protocol Reject #106 (Opened) Oct 26 21:44:52 ppp 9410 [wan] IPV6CP: SendConfigReq #1 Oct 26 21:44:52 ppp 9410 [wan] IPV6CP: state change Starting --> Req-Sent Oct 26 21:44:52 ppp 9410 [wan] IPV6CP: Up event Oct 26 21:44:52 ppp 9410 [wan] SECDNS 0.0.0.0 Oct 26 21:44:52 ppp 9410 [wan] PRIDNS 0.0.0.0 Oct 26 21:44:52 ppp 9410 [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Oct 26 21:44:52 ppp 9410 [wan] IPADDR 0.0.0.0 Oct 26 21:44:52 ppp 9410 [wan] IPCP: SendConfigReq #1 Oct 26 21:44:52 ppp 9410 [wan] IPCP: state change Starting --> Req-Sent Oct 26 21:44:52 ppp 9410 [wan] IPCP: Up event Oct 26 21:44:52 ppp 9410 [wan] IPV6CP: LayerStart Oct 26 21:44:52 ppp 9410 [wan] IPV6CP: state change Initial --> Starting Oct 26 21:44:52 ppp 9410 [wan] IPV6CP: Open event Oct 26 21:44:52 ppp 9410 [wan] IPCP: LayerStart Oct 26 21:44:52 ppp 9410 [wan] IPCP: state change Initial --> Starting Oct 26 21:44:52 ppp 9410 [wan] IPCP: Open event Oct 26 21:44:52 ppp 9410 [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps Oct 26 21:44:52 ppp 9410 [wan_link0] Link: Join bundle "wan" Oct 26 21:44:52 ppp 9410 [wan_link0] Link: Matched action 'bundle "wan" ""' Oct 26 21:44:52 ppp 9410 [wan_link0] LCP: authorization successful Oct 26 21:44:52 ppp 9410 [wan_link0] CHAP: rec'd SUCCESS #191 len: 4 Oct 26 21:44:52 ppp 9410 [wan_link0] CHAP: sending RESPONSE #191 len: 51 Oct 26 21:44:52 ppp 9410 [wan_link0] CHAP: Using authname "XXXXXXXXXX@mdsl.mnet-online.de" Oct 26 21:44:52 ppp 9410 [wan_link0] Name: "ac3.nue2" Oct 26 21:44:52 ppp 9410 [wan_link0] CHAP: rec'd CHALLENGE #191 len: 31 Oct 26 21:44:52 ppp 9410 [wan_link0] LCP: LayerUp Oct 26 21:44:52 ppp 9410 [wan_link0] LCP: auth: peer wants CHAP, I want nothing Oct 26 21:44:52 ppp 9410 [wan_link0] LCP: state change Ack-Sent --> Opened Oct 26 21:44:52 ppp 9410 [wan_link0] MAGICNUM 0xe30caada Oct 26 21:44:52 ppp 9410 [wan_link0] MRU 1492 Oct 26 21:44:52 ppp 9410 [wan_link0] PROTOCOMP Oct 26 21:44:52 ppp 9410 [wan_link0] LCP: rec'd Configure Ack #1 (Ack-Sent) Oct 26 21:44:52 ppp 9410 [wan_link0] LCP: state change Req-Sent --> Ack-Sent Oct 26 21:44:52 ppp 9410 [wan_link0] MAGICNUM 0x0397bc67 Oct 26 21:44:52 ppp 9410 [wan_link0] AUTHPROTO CHAP MD5 Oct 26 21:44:52 ppp 9410 [wan_link0] MRU 1492 Oct 26 21:44:52 ppp 9410 [wan_link0] LCP: SendConfigAck #105 Oct 26 21:44:52 ppp 9410 [wan_link0] MAGICNUM 0x0397bc67 Oct 26 21:44:52 ppp 9410 [wan_link0] AUTHPROTO CHAP MD5 Oct 26 21:44:52 ppp 9410 [wan_link0] MRU 1492 Oct 26 21:44:52 ppp 9410 [wan_link0] LCP: rec'd Configure Request #105 (Req-Sent) Oct 26 21:44:52 ppp 9410 [wan_link0] MAGICNUM 0xe30caada Oct 26 21:44:52 ppp 9410 [wan_link0] MRU 1492 Oct 26 21:44:52 ppp 9410 [wan_link0] PROTOCOMP Oct 26 21:44:52 ppp 9410 [wan_link0] LCP: SendConfigReq #1 Oct 26 21:44:52 ppp 9410 [wan_link0] LCP: state change Starting --> Req-Sent Oct 26 21:44:52 ppp 9410 [wan_link0] LCP: Up event Oct 26 21:44:52 ppp 9410 [wan_link0] Link: UP event Oct 26 21:44:52 ppp 9410 [wan_link0] PPPoE: connection successful Oct 26 21:44:52 ppp 9410 PPPoE: rec'd ACNAME "ac3.nue2" Oct 26 21:44:52 ppp 9410 [wan_link0] PPPoE: Connecting to '' Oct 26 21:44:52 ppp 9410 [wan_link0] LCP: LayerStart Oct 26 21:44:52 ppp 9410 [wan_link0] LCP: state change Initial --> Starting Oct 26 21:44:52 ppp 9410 [wan_link0] LCP: Open event Oct 26 21:44:52 kernel ng0: changing name to 'pppoe0' Oct 26 21:44:52 ppp 9410 [wan_link0] Link: OPEN event Oct 26 21:44:52 ppp 9410 [wan] Bundle: Interface ng0 created Oct 26 21:44:52 ppp 9410 web: web is not running Oct 26 21:44:52 ppp 9410 process 9410 started, version 5.9 Oct 26 21:44:52 ppp 9410 Multi-link PPP daemon for FreeBSD Oct 26 21:44:52 kernel vtnet1: link state changed to UP Oct 26 21:44:52 kernel done. Oct 26 21:44:52 check_reload_status 395 Linkup starting vtnet1 Oct 26 21:44:52 php 411 rc.bootup: The command '/sbin/ifconfig 'gif0' description '4IN6'' returned exit code '1', the output was 'ifconfig: interface gif0 does not exist' Oct 26 21:44:52 check_reload_status 395 Linkup starting vtnet0 Oct 26 21:44:52 kernel vtnet0: link state changed to UP
As I already mentioned: With this configuration the 4IN6 tunnel does not work.
Thanks again for having a look into this.
-
Hmm. Even with that don't see it trying to restart the gif tunnel (even if it would fail) after the WAN connects and gets a new IPv6 address and I would expect it to trigger that.
It could be because it's link-local only and that is not seen as a valid address. Though it is valid for a transport link and that's common on WAN. Or potentially it comes up at boot and somethings are suppressed during boot to prevent flapping.However what you're seeing is exactly this: https://redmine.pfsense.org/issues/8273
Which should be fixed by this: https://redmine.pfsense.org/issues/6507
But that is in 2.6.Does manually running
/etc/rc.newwanipv6 lan
after boot bring the gif tunnel up? What is logged when you do that?Steve