No internet connection after upgrade from April 20 snapshot to May 19
-
I suppose between the 'Rename interface ng0 to pppoe0' and the manual re-connect you do have these 2 lines?:
Jun 10 19:49:13 php-fpm 322 /rc.newwanip: rc.newwanip: on (IP address: 10.30.20.163) (interface: WAN[wan]) (real interface: pppoe0). Jun 10 19:49:13 php-fpm 322 /rc.newwanip: rc.newwanip: Info: starting on pppoe0.
And then the "rc.newwanip" just stops running .? While it should log a few more lines and set the gateway like in previous posts.? I think there is a race condition there where the script exit's during bootup...
-
@piba
Here is more:Jun 10 19:50:05 upsd 28485 User monuser@::1 logged into UPS [SMK-1000A] Jun 10 19:50:03 upsd 28485 Startup successful Jun 10 19:50:03 upsd 28483 Can't connect to UPS [SMK-1000A] (snmp-ups-SMK-1000A): No such file or directory Jun 10 19:50:03 upsd 28483 listening on 127.0.0.1 port 3493 Jun 10 19:50:03 upsd 28483 listening on ::1 port 3493 Jun 10 19:50:02 php-cgi notify_monitor.php: Could not send the message to w***n@gmail.com -- Error: Failed to connect to mail.in***.**:25 [SMTP: Failed to connect socket: Network is unreachable (code: -1, response: )] Jun 10 19:50:02 upsmon 27593 Startup successful Jun 10 19:50:02 php-fpm 334 /rc.start_packages: Starting service nut Jun 10 19:50:02 php-fpm 334 /rc.start_packages: Restarting/Starting all packages. Jun 10 19:50:02 kernel done. Jun 10 19:50:02 syslogd kernel boot file is /boot/kernel/kernel Jun 10 19:50:02 syslogd exiting on signal 15 Jun 10 19:50:02 syslogd Logging subprocess 9161 (exec /usr/local/sbin/sshlockout_pf 15) exited due to signal 15. Jun 10 19:50:00 root /etc/rc.d/hostid: WARNING: hostid: unable to figure out a UUID from DMI data, generating a new one Jun 10 19:50:00 php-fpm 334 /rc.newwanip: rc.newwanip: on (IP address: 84.52.**.200) (interface: WAN[wan]) (real interface: pppoe0). Jun 10 19:50:00 php-fpm 334 /rc.newwanip: rc.newwanip: Info: starting on pppoe0. Jun 10 19:50:00 kernel done. Jun 10 19:49:59 check_reload_status Linkup starting igb1 Jun 10 19:49:59 kernel igb1: link state changed to UP Jun 10 19:49:59 ppp [wan] IFACE: Rename interface ng0 to pppoe0 Jun 10 19:49:59 ppp [wan] IFACE: Up event Jun 10 19:49:59 check_reload_status rc.newwanip starting pppoe0 Jun 10 19:49:58 php-fpm 335 /rc.dyndns.update: Curl error occurred: Could not resolve host: freedns.afraid.org Jun 10 19:49:58 kernel ng_pppoe[12]: no matching session Jun 10 19:49:58 kernel ng_pppoe[12]: no matching session Jun 10 19:49:58 check_reload_status Rewriting resolv.conf Jun 10 19:49:58 ppp [wan] 84.52.**.200 -> 212.7.29.236 Jun 10 19:49:58 ppp [wan] IPCP: LayerUp Jun 10 19:49:58 ppp [wan] IPCP: state change Ack-Sent --> Opened Jun 10 19:49:58 ppp [wan] SECDNS 212.7.9.34 Jun 10 19:49:58 ppp [wan] PRIDNS 212.7.0.33 Jun 10 19:49:58 ppp [wan] IPADDR 84.52.xx.200 Jun 10 19:49:58 ppp [wan] IPCP: rec'd Configure Ack #3 (Ack-Sent) Jun 10 19:49:58 ppp [wan] SECDNS 212.7.9.34 Jun 10 19:49:58 ppp [wan] PRIDNS 212.7.0.33 Jun 10 19:49:58 ppp [wan] IPADDR 84.52.xx.200 Jun 10 19:49:58 ppp [wan] IPCP: SendConfigReq #3 Jun 10 19:49:58 ppp [wan] SECDNS 212.7.9.34 Jun 10 19:49:58 ppp [wan] PRIDNS 212.7.0.33 Jun 10 19:49:58 ppp [wan] 84.52.xx.200 is OK Jun 10 19:49:58 ppp [wan] IPADDR 84.52.xx.200 Jun 10 19:49:58 ppp [wan] IPCP: rec'd Configure Nak #2 (Ack-Sent) Jun 10 19:49:58 ppp [wan] IPV6CP: LayerFinish Jun 10 19:49:58 ppp [wan] IPV6CP: state change Req-Sent --> Stopped Jun 10 19:49:58 ppp [wan] IPV6CP: protocol was rejected by peer Jun 10 19:49:58 ppp [wan_link0] LCP: protocol IPV6CP was rejected Jun 10 19:49:58 ppp [wan_link0] LCP: rec'd Protocol Reject #2 (Opened) Jun 10 19:49:58 ppp [wan] SECDNS 0.0.0.0 Jun 10 19:49:58 ppp [wan] PRIDNS 0.0.0.0 Jun 10 19:49:58 ppp [wan] IPADDR 0.0.0.0 Jun 10 19:49:58 ppp [wan] IPCP: SendConfigReq #2 Jun 10 19:49:58 ppp [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Jun 10 19:49:58 ppp [wan] IPCP: rec'd Configure Reject #1 (Ack-Sent) Jun 10 19:49:58 ppp [wan] IPCP: state change Req-Sent --> Ack-Sent Jun 10 19:49:58 ppp [wan] IPADDR 212.7.29.236 Jun 10 19:49:58 ppp [wan] IPCP: SendConfigAck #1 Jun 10 19:49:58 ppp [wan] 212.7.29.236 is OK Jun 10 19:49:58 ppp [wan] IPADDR 212.7.29.236 Jun 10 19:49:58 ppp [wan] IPCP: rec'd Configure Request #1 (Req-Sent) Jun 10 19:49:58 ppp [wan] IPV6CP: SendConfigReq #1 Jun 10 19:49:58 ppp [wan] IPV6CP: state change Starting --> Req-Sent Jun 10 19:49:58 ppp [wan] IPV6CP: Up event Jun 10 19:49:58 ppp [wan] SECDNS 0.0.0.0 Jun 10 19:49:58 ppp [wan] PRIDNS 0.0.0.0 Jun 10 19:49:58 ppp [wan] COMPPROTO VJCOMP, 16 comp. channels, no comp-cid Jun 10 19:49:58 ppp [wan] IPADDR 0.0.0.0 Jun 10 19:49:58 ppp [wan] IPCP: SendConfigReq #1 Jun 10 19:49:58 ppp [wan] IPCP: state change Starting --> Req-Sent Jun 10 19:49:58 ppp [wan] IPCP: Up event Jun 10 19:49:58 ppp [wan] IPV6CP: LayerStart Jun 10 19:49:58 ppp [wan] IPV6CP: state change Initial --> Starting Jun 10 19:49:58 ppp [wan] IPV6CP: Open event Jun 10 19:49:58 ppp [wan] IPCP: LayerStart Jun 10 19:49:58 ppp [wan] IPCP: state change Initial --> Starting Jun 10 19:49:58 ppp [wan] IPCP: Open event Jun 10 19:49:58 ppp [wan] Bundle: Status update: up 1 link, total bandwidth 64000 bps Jun 10 19:49:58 ppp [wan_link0] Link: Join bundle "wan" Jun 10 19:49:58 ppp [wan_link0] Link: Matched action 'bundle "wan" ""' Jun 10 19:49:58 ppp [wan_link0] LCP: authorization successful Jun 10 19:49:58 ppp [wan_link0] CHAP: rec'd SUCCESS #1 len: 4 Jun 10 19:49:58 ppp [wan_link0] CHAP: sending RESPONSE #1 len: 33 Jun 10 19:49:58 ppp [wan_link0] CHAP: Using authname "yyyyy" Jun 10 19:49:58 ppp [wan_link0] Name: "k18-29-236" Jun 10 19:49:58 ppp [wan_link0] CHAP: rec'd CHALLENGE #1 len: 31 Jun 10 19:49:58 ppp [wan_link0] LCP: LayerUp Jun 10 19:49:58 ppp [wan_link0] LCP: auth: peer wants CHAP, I want nothing Jun 10 19:49:58 ppp [wan_link0] LCP: state change Ack-Sent --> Opened Jun 10 19:49:58 ppp [wan_link0] MAGICNUM 0x2e5af1e0 Jun 10 19:49:58 ppp [wan_link0] MRU 1492 Jun 10 19:49:58 ppp [wan_link0] PROTOCOMP Jun 10 19:49:58 ppp [wan_link0] LCP: rec'd Configure Ack #1 (Ack-Sent) Jun 10 19:49:58 ppp [wan_link0] LCP: state change Req-Sent --> Ack-Sent Jun 10 19:49:58 ppp [wan_link0] MAGICNUM 0xcde7b797 Jun 10 19:49:58 ppp [wan_link0] AUTHPROTO CHAP MD5 Jun 10 19:49:58 ppp [wan_link0] MRU 1492 Jun 10 19:49:58 ppp [wan_link0] LCP: SendConfigAck #1 Jun 10 19:49:58 ppp [wan_link0] MAGICNUM 0xcde7b797 Jun 10 19:49:58 ppp [wan_link0] AUTHPROTO CHAP MD5 Jun 10 19:49:58 ppp [wan_link0] MRU 1492 Jun 10 19:49:58 ppp [wan_link0] LCP: rec'd Configure Request #1 (Req-Sent) Jun 10 19:49:58 ppp [wan_link0] MAGICNUM 0x2e5af1e0 Jun 10 19:49:58 ppp [wan_link0] MRU 1492 Jun 10 19:49:58 ppp [wan_link0] PROTOCOMP Jun 10 19:49:58 ppp [wan_link0] LCP: SendConfigReq #1 Jun 10 19:49:58 ppp [wan_link0] LCP: state change Starting --> Req-Sent Jun 10 19:49:58 ppp [wan_link0] LCP: Up event Jun 10 19:49:58 ppp [wan_link0] Link: UP event Jun 10 19:49:58 ppp [wan_link0] PPPoE: connection successful Jun 10 19:49:58 ppp PPPoE: rec'd ACNAME "k18-29-236" Jun 10 19:49:57 kernel done Jun 10 19:49:57 php-cgi rc.bootup: IPsec ERROR: Could not find phase 1 source for connection . Omitting from configuration file. Jun 10 19:49:57 kernel .done. Jun 10 19:49:57 kernel .... Jun 10 19:49:57 check_reload_status Updating all dyndns Jun 10 19:49:57 kernel done. Jun 10 19:49:57 kernel done. Jun 10 19:49:57 php-cgi rc.bootup: NTPD is starting up. Jun 10 19:49:57 check_reload_status Linkup starting igb0 Jun 10 19:49:57 kernel igb0: link state changed to UP Jun 10 19:49:56 kernel done. Jun 10 19:49:56 php-cgi rc.bootup: sync unbound done. Jun 10 19:49:56 kernel Starting DNS Resolver...done. Jun 10 19:49:56 php-cgi rc.bootup: gateways_arr:Array ( [WAN_PPPOE] => Array ( [dynamic] => [ipprotocol] => inet [gateway] => [interface] => pppoe0 [friendlyiface] => wan [name] => WAN_PPPOE [attribute] => system [descr] => Interface WAN_PPPOE Gateway ) [Null4] => Array ( [name] => Null4 [interface] => lo0 [ipprotocol] => inet [gateway] => 127.0.0.1 ) [Null6] => Array ( [name] => Null6 [interface] => lo0 [ipprotocol] => inet6 [gateway] => ::1 ) ) Jun 10 19:49:56 php-cgi rc.bootup: fixup_default_gateway dfltgwdown: upgw: dfltgwname: , gwdefault: Jun 10 19:49:56 php-cgi rc.bootup: gateways_arr:Array ( [WAN_PPPOE] => Array ( [dynamic] => [ipprotocol] => inet [gateway] => [interface] => pppoe0 [friendlyiface] => wan [name] => WAN_PPPOE [attribute] => system [descr] => Interface WAN_PPPOE Gateway ) [Null4] => Array ( [name] => Null4 [interface] => lo0 [ipprotocol] => inet [gateway] => 127.0.0.1 ) [Null6] => Array ( [name] => Null6 [interface] => lo0 [ipprotocol] => inet6 [gateway] => ::1 ) ) Jun 10 19:49:56 kernel load_dn_aqm dn_aqm PIE loaded Jun 10 19:49:56 kernel load_dn_aqm dn_aqm CODEL loaded Jun 10 19:49:56 kernel load_dn_sched dn_sched FQ_PIE loaded Jun 10 19:49:56 kernel load_dn_sched dn_sched FQ_CODEL loaded Jun 10 19:49:56 kernel load_dn_sched dn_sched PRIO loaded Jun 10 19:49:56 kernel load_dn_sched dn_sched WF2Q+ loaded Jun 10 19:49:56 kernel load_dn_sched dn_sched RR loaded Jun 10 19:49:56 kernel load_dn_sched dn_sched QFQ loaded Jun 10 19:49:56 kernel load_dn_sched dn_sched FIFO loaded Jun 10 19:49:56 kernel DUMMYNET 0 with IPv6 initialized (100409) Jun 10 19:49:56 kernel pflog0: promiscuous mode enabled Jun 10 19:49:56 php-cgi rc.bootup: fixup_default_gateway dfltgwdown: upgw: dfltgwname:WAN_PPPOE , gwdefault:WAN_PPPOE Jun 10 19:49:56 php-cgi rc.bootup: The command '/sbin/route delete -host 80.72.146.2' returned exit code '1', the output was 'route: route has not been found delete host 80.72.146.2 fib 0: not in table' Jun 10 19:49:56 php-cgi rc.bootup: The command '/sbin/route delete -host 74.82.42.42' returned exit code '1', the output was 'route: route has not been found delete host 74.82.42.42 fib 0: not in table' Jun 10 19:49:56 php-cgi rc.bootup: The command '/sbin/route delete -host 8.8.4.4' returned exit code '1', the output was 'route: route has not been found delete host 8.8.4.4 fib 0: not in table' Jun 10 19:49:55 php-cgi rc.bootup: Resyncing OpenVPN instances. Jun 10 19:49:53 syslogd sendto: Network is unreachable Jun 10 19:49:53 sshlockout 9161 sshlockout/webConfigurator v3.0 starting up Jun 10 19:49:53 syslogd sendto: Network is unreachable Jun 10 19:49:53 sshd 9034 Server listening on 0.0.0.0 port 22. Jun 10 19:49:53 syslogd sendto: Network is unreachable Jun 10 19:49:53 sshd 9034 Server listening on :: port 22. Jun 10 19:49:52 syslogd sendto: Network is unreachable Jun 10 19:49:52 ppp [wan_link0] PPPoE: Connecting to '' Jun 10 19:49:52 syslogd sendto: Network is unreachable Jun 10 19:49:52 ppp [wan_link0] LCP: LayerStart Jun 10 19:49:52 syslogd sendto: Network is unreachable Jun 10 19:49:52 ppp [wan_link0] LCP: state change Initial --> Starting Jun 10 19:49:52 syslogd sendto: Network is unreachable Jun 10 19:49:52 ppp [wan_link0] LCP: Open event Jun 10 19:49:52 syslogd sendto: Network is unreachable Jun 10 19:49:52 ppp [wan_link0] Link: OPEN event Jun 10 19:49:52 syslogd sendto: Network is unreachable Jun 10 19:49:52 kernel ng0: changing name to 'pppoe0' Jun 10 19:49:52 syslogd sendto: Network is unreachable Jun 10 19:49:52 syslogd sendto: Network is unreachable Jun 10 19:49:52 ppp [wan] Bundle: Interface ng0 created Jun 10 19:49:52 syslogd sendto: Network is unreachable Jun 10 19:49:52 ppp web: web is not running Jun 10 19:49:52 syslogd sendto: Network is unreachable Jun 10 19:49:52 ppp process 7276 started, version 5.8 (nobody@pfSense_master_amd64-pfSense_devel-job-02 16:31 21-Oct-2017) Jun 10 19:49:52 syslogd sendto: Network is unreachable Jun 10 19:49:52 syslogd sendto: Network is unreachable Jun 10 19:49:52 ppp Multi-link PPP daemon for FreeBSD Jun 10 19:49:52 syslogd sendto: Network is unreachable
-
Yep thats the 2 lines right there..
Jun 10 19:50:00 php-fpm 334 /rc.newwanip: rc.newwanip: on (IP address: 84.52.**.200) (interface: WAN[wan]) (real interface: pppoe0). Jun 10 19:50:00 php-fpm 334 /rc.newwanip: rc.newwanip: Info: starting on pppoe0.
So indeed in your case it is 'aborting' that script before its done running.
Seems like this 'exit' is supposed to be avoiding a race condition where its actually causing one...:
https://github.com/pfsense/pfsense/blob/d84eec807d6216cfbc073438ce57e01f1c52a2f4/src/etc/rc.newwanip#L192@jimp any insights on what would be the right order to call things?
- initialize PPPOE-client while booting
- initialize routes and packages and rules and stuff after PPPOE gets connected
- finish the rc.newwanip to configure routes and other things that depends on the newly assigned wan-ip..
- finish booting..
I think it was previously working because every call to return_gateway_groups_array() would again try and fix the gateways.. and eventually one did catch.. Now the return_gateway_groups_array() most of the time skips these actions as fixing the gateway should not happen as a 'side-effect' of 'requesting information'.. But that does seem to cause this problem..
-
Perhaps the fix could be as simple as removing that 'exit' from the rc.newwanip .? (in addition to the PR made)
-
@piba
I've deleted this line and this fixes the problem with connection on boot, really. -
@w0w
I've discussed with jimp, and he didn't like removing the exit completely to avoid bringing the old previous race condition back. we agreed upon a specific 'ppp check' to avoid the exit. Can you put the exit back in, but apply this extra check instead.? That should still fix the issue.. does it.? :https://github.com/pfsense/pfsense/pull/3947/commits/627b0941889f4b19ad419ddfe01d329bef2c2bd6
-
@piba
Looks like with BOTH (gwlib.inc and rc.newwanip) fixes applied — I now have internet connection. One thing is still need to be fixed — after upgrade from previous version and after applying those patches I need also to select default gateway in drop-down list on system_gateways.php page.
If I restore old configuration on patched system the same thing happens also, I need manually select gateway on system_gateways.php via GUI, is it feature or bug? -
Yes the first link https://github.com/pfsense/pfsense/pull/3947 contains 3 fixes/commits, the 2 you refer to, and one that fixes the displaying of the IPv6 for a IPv4 gateway..
The gui 'none' selection is is still something to fix. Lets call that a 'unwanted feature' ;) . Ill probably work on that soon..
-
@piba
Thank you, let me know if you need further testing. -
@w0w
Thank you for testing and reporting back each time :).Can you try latest snapshot? Its build with these (slightly modified) fixes included.
p.s. not the 'none' selection yet though, still working on that.
-
@piba
I have tried this one:2.4.4-DEVELOPMENT (amd64) built on Sat Jun 23 01:57:55 EDT 2018 FreeBSD 11.2-RC3
I've found that internet not working with this snapshot on reboot, but both fixes are present.
I think it's modified line that was looked likeif (platform_booting() && strpos($interface_real, "ppp") !== 0) {
before,
and now it'sif (platform_booting() && in_array(substr($interface_real, 0, 3), array("ppp", "ppt", "l2t"))) {
because if I change it back, it works again.
-
@w0w
Ah crap, i forgot to do the inverse, '!'.if (platform_booting() && !in_array(substr($interface_real, 0, 3), array("ppp", "ppt", "l2t"))) {
sorry, thanks for testing!
new PR made: https://github.com/pfsense/pfsense/pull/3956
-
@piba This one is much better
It works! -
As expected, latest snapshot containing this PR boots normally.
-
@w0w
Thanks, added your confirmation to the redmine ticked so it can be closed. -
@piba
Please let me know when you need testing gui 'none' selection fix -
@w0w
The commit was merged, but not build yet. next snapshot should contain a new 'automatic' option which would be the default for the gateway selection, also a option to move gateways up/down on the list with checkboxes and anchor click. The option 'none' should now also actually be none.. I guess all of those things can use a little testing once it gets build .. -
@piba
Here is my test result. If I select "Automatic" option in GUI then everything looks OK, I have internet and default gateway, but when I try reboot the firewall, on next boot there is no internet and default gateway anymore, sounds familiar?
This easy to fix, just pressing "save" on system_gateways.php and "Apply changes", it immediately starts working and I see this line in log:/system_gateways.php: Default gateway setting Interface WAN_PPPOE Gateway as default.
There is no such/similar line during boot, so automatic selection does not trig for some reason.
How can I help to debug this? -
@w0w
Thanks again for testing. We seem to have hit catch22 issue here.'Automatic' selection takes the gateway 'status' into account which depends on dpinger, which depends on routes to the monitor-targets being configured before hand so to the monitor target will be using the correct gateway, which while configuring routes it also configures the default route which depends on the dpinger already running..
Hmm... This needs a bit more thought..
-
@piba
Maybe these questions sound silly, but anyway I'll ask
If we have a bunch of gateways, ex. multiple WANs, what this "automatic" selection is supposed to do generally?
When we have single gateway found on a system, then we can skip status check and just select it as "default", no?