Upgrade from 12/13 to 12/18 -> PPPoE dead…

jlepthien

Hi there,

I just updated and now PPPoE doesn't seem to be working anymore. Curious thing is that it is also not working with my older snapshot anymore…

Here is what the logs say....

ppp.log

Jan  1 01:28:22 voldemort ppp: [wan_link0] Link: reconnection attempt 200
Jan  1 01:28:22 voldemort ppp: [wan_link0] PPPoE: can't connect "[11]:"->"mpd9518-0" and "[f]:"->"left": No such file or directory
Jan  1 01:28:22 voldemort ppp: [wan_link0] can't remove hook mpd9518-0 from node "[11]:": No such file or directory
Jan  1 01:28:22 voldemort ppp: [wan_link0] Link: DOWN event
Jan  1 01:28:22 voldemort ppp: [wan_link0] LCP: Down event
Jan  1 01:28:22 voldemort ppp: [wan_link0] Link: reconnection attempt 201 in 1 seconds
Jan  1 01:28:23 voldemort ppp: [wan_link0] Link: reconnection attempt 201
Jan  1 01:28:23 voldemort ppp: [wan_link0] PPPoE: can't connect "[11]:"->"mpd9518-0" and "[f]:"->"left": No such file or directory
Jan  1 01:28:23 voldemort ppp: [wan_link0] can't remove hook mpd9518-0 from node "[11]:": No such file or directory
Jan  1 01:28:23 voldemort ppp: [wan_link0] Link: DOWN event
Jan  1 01:28:23 voldemort ppp: [wan_link0] LCP: Down event
Jan  1 01:28:23 voldemort ppp: [wan_link0] Link: reconnection attempt 202 in 4 seconds

Where should this mpdxxx file be? Is that probably the problem? I also ran the setup wizard again with no solution…

system.log

Jan  1 01:32:26 voldemort ppp: [wan_link0] Link: DOWN event
Jan  1 01:32:26 voldemort ppp: [wan_link0] LCP: Down event
Jan  1 01:32:26 voldemort ppp: [wan_link0] Link: reconnection attempt 298 in 3 seconds
Jan  1 01:32:29 voldemort ppp: [wan_link0] Link: reconnection attempt 298
Jan  1 01:32:29 voldemort ppp: [wan_link0] PPPoE: can't connect "[11]:"->"mpd9518-0" and "[f]:"->"left": No such file or directory
Jan  1 01:32:29 voldemort ppp: [wan_link0] can't remove hook mpd9518-0 from node "[11]:": No such file or directory
Jan  1 01:32:29 voldemort ppp: [wan_link0] Link: DOWN event
Jan  1 01:32:29 voldemort ppp: [wan_link0] LCP: Down event
Jan  1 01:32:29 voldemort ppp: [wan_link0] Link: reconnection attempt 299 in 2 seconds

Any hints?

jlepthien

Also when I try to manually start the session with '/usr/local/sbin/mpd5 -b -k -d /var/etc -f mpd_wan.conf -p /var/run/pppoe_wan.pid -s ppp pppoeclient' I get the following error:

/libexec/ld-elf.so.1: Shared object "libexpat.so.6" not found, required by "mpd5"

BlueMatt

Same problem here, just got it resolved.
Was fixed when I reverted my repo from 12/17 22:09 to 12/12. Not sure what it was that killed it but its something that appears on https://rcs.pfsense.org/projects/pfsense/repos/CustomDDNS/commits/31bfb9f40a0e5a34713455f4b9df1c432e1b4fc1.

jlepthien

Ok. So I'll wait for the next snap then…

BlueMatt

No I was just saying I got my box fixed (by reverting to 12/12).
I'd be willing to bet the problem is a result of the changes to etc/inc/vslb.inc, but I could be wrong…

BlueMatt

@BlueMatt:

I'd be willing to bet the problem is a result of the changes to etc/inc/vslb.inc, but I could be wrong…

No I was definitely looking at the diff backwards (undoing changes messes with your head), not really sure where the issue is at the moment. More debugging is required.

chpalmer

You guys had me worried but at one of my locations Im still on-

2.0-BETA4 (i386)
built on Thu Dec 16 14:34:04 EST 2010

pppoe working for me on this build. Guess Ill hold off updates for a bit.

rafael.cardoso

Using 2.0-BETA4 (i386) built on Sat Dec 18 09:51:58 EST 2010 pppoe works fine

jlepthien

@rafael.cardoso:

Using 2.0-BETA4 (i386) built on Sat Dec 18 09:51:58 EST 2010 pppoe works fine

Yeah but that seems to be a newer build…Will check that one....

BlueMatt

@rafael.cardoso:

Using 2.0-BETA4 (i386) built on Sat Dec 18 09:51:58 EST 2010 pppoe works fine

When I used the same build (with git update), it didn't work, so clearly it does not plague all PPPoE users.
Rafael, can you comment as to whether the PPPoE link is your primary WAN and any what type of link it actually is (DSL, etc).
Also, chpalmer, would you mind upgrading to see if the problem does effect you as well. The date might help narrow down exactly which commit caused the problem.
Sadly, I am on vacation and can't debug the problem myself. If anyone has an extra hour or two, might they revert to Monday's snapshot and apply each git commmit from there to see when the problem occurs?
Otherwise can a dev comment as to what might be causing this?

jlepthien

Tried again with pfSense-2.0-BETA4-4g-20101218-1051-nanobsd-upgrade.img.gz snap but it didn't work. Also tried a firmware default and then just adding the PPPoE settings with no luck…

Will do just the same with pfSense-2.0-BETA4-4g-20101218-2216-nanobsd-upgrade.img.gz now. But the weird thing is that after my upgrade also my other slice with the before working config never worked again...
I hope I do not have to open my box again to do a full fresh install. Any hints on how I can do a really fresh install otherwise? By booting into the other slice? Is that possible?

jlepthien

Weird. Did another reboot with my box on standard config with PPPoE and it works. Just wanted to boot up in order to update to latest snap. Will do so now and then restore my config. Will tell you guys if it works…

sburgiel

PPPoE was working for me in build Fri Dec 17 14:14:00 EST 2010. It stopped working (mpdxxxx errors in the PPP log) when I updated to build Fri Dec 17 23:56:27 EST 2010. My only WAN link is PPPoE with DSL, and I have reverted to the earlier (working) build.

jlepthien

Ok. Does not work for me when I restore my config then. Actually I also tried some older configs…

Here is what I get when booting. Some weird errors:

Warning: chown(): Unable to find uid for root in /etc/inc/config.lib.inc on line 833
done.

Warning: chown(): Unable to find uid for admin in /etc/inc/auth.inc on line 411

Warning: chown(): Unable to find uid for admin in /etc/inc/auth.inc on line 422

Warning: chown(): Unable to find uid for nobody in /etc/inc/rrd.inc on line 686

Warning: chown(): Unable to find uid for jle in /etc/inc/auth.inc on line 411
done.

Also saw a panic when it first booted with the restored config. Another reboot and it doesn't panic anymore but still the other errors occur and no PPPoE…

Fatal trap 12: page fault while in kernel mode
cpuid = 0; apic id = 00
fault virtual address   = 0x4
fault code              = supervisor write, page not present
instruction pointer     = 0x20:0xc0a18c21
stack pointer           = 0x28:0xe37a1a18
frame pointer           = 0x28:0xe37a1a38
code segment            = base 0x0, limit 0xfffff, type 0x1b
                        = DPL 0, pres 1, def32 1, gran 1
processor eflags        = interrupt enabled, resume, IOPL = 0
current process         = 44539 (initial thread)
trap number             = 12
panic: page fault
cpuid = 0
Uptime: 45s
Cannot dump. Device not defined or unavailable.
Automatic reboot in 15 seconds - press a key on the console to abort

jlepthien

So there seems to be something really wrong with my config backups. That makes me quite afraid that there could be something wrong in the backup system. I will now update to the latest snap and then try to restore section per section of the config and see where it breaks.

I also have my graphs in my config…

jlepthien

Hmm. Tried to restore part of the config but nothing changed…I tried to restore interfaces first, rebooted but no change at all. Stays on default IP on LAN etc...

Tried to restore aliases and nothing....

jlepthien

Tried again with latest snap from 12/19. Blank config with just PPPoE enabled so that my internet connection works. Tried just restoring the aliases from my config files but they do not appear on aliases. Nothing there. Did a reboot then but still nothing. I can see that it was imported under Config History though…

rafael.cardoso

BlueMatt, I'm using pppoe as the WAN interface, it is an ADSL actually did an update for version 1.2.3, but the initial boot camp the username and password were blank being filled to function normally again :)

jlepthien

Can anyone from the dev team try to import my config? Just to see if it will work?

Thanks…

eri--

Try this manually
https://rcs.pfsense.org/projects/pfsense/repos/mainline/commits/92a1c8e6caca910ae1f8c54751bffebd45d87682

or wait for a snapshot with the patch applied.

jlepthien

Thanks ermal, but the PPPoE is working now. I meant if someone could check why my config is not importable not even just some parts like firewall rules or aliases. Tried with older configs as well…
Would hate to start from scratch...

jlepthien

Tried again to restore just the aliases and the following shows up in my system.log:

Dec 21 17:17:46 pfSense php: /diag_backup.php: XML error: no aliases object found!

I have the following in my config.xml though:

 <aliases><alias><name>AppleServers</name>

<address>17.155.0.0/16 79.223.0.0/16 80.149.0.0/16 87.154.0.0/16</address>

			<type>network</type>
			<detail>Entry added Thu, 21 Oct 2010 00:20:31 +0200||Entry added Thu, 21 Oct 2010 00:20:31 +0200||Entry added Thu, 21 Oct 2010 20:35:29 +0200||Entry added Thu, 21 Oct 2010 20:38:41 +0200</detail></alias> 
		 <alias><name>Dumbledore</name>

<address>172.16.100.5</address>

			<type>host</type>
			<detail>Entry added Thu, 21 Oct 2010 14:46:01 +0200</detail></alias> 
		 <alias><name>DynDNS_Hostname</name>

<address>voldemort.endofinternet.org</address>

			<type>network</type>
			<detail>Entry added Fri, 08 Oct 2010 15:05:25 +0200</detail></alias> 
		 <alias><name>FaceTimePorts</name>

<address>3478:3497 16384:16386 16393:16402</address>

			<type>port</type>
			<detail>Entry added Mon, 29 Nov 2010 23:04:17 +0100||Entry added Mon, 29 Nov 2010 23:04:17 +0100||Entry added Mon, 29 Nov 2010 23:04:17 +0100</detail></alias> 
		 <alias><name>FiletransferPorts</name>

<address>21 22</address>

			<type>port</type>
			<detail>Entry added Wed, 24 Nov 2010 23:14:01 +0100||Entry added Wed, 24 Nov 2010 23:14:01 +0100</detail></alias> 
		 <alias><name>Hermione</name>

<address>172.16.100.50</address>

			<type>host</type>
			<detail>Entry added Wed, 20 Oct 2010 22:09:04 +0200</detail></alias> 
		 <alias><name>LocalAreaNetwork</name>

<address>10.0.100.0/24</address>

			<type>network</type>
			<detail>Entry added Tue, 19 Oct 2010 17:02:57 +0200</detail></alias> 
		 <alias><name>LocalNetworks</name>

<address>10.0.100.0/24 172.16.100.0/24 192.168.100.0/24</address>

			<type>network</type>
			<detail>Entry added Tue, 19 Oct 20109:38:15 +0200||Entry added Thu, 21 Oct 2010 13:28:29 +0200||Entry added Sun, 05 Dec 2010 20:28:57 +0100</detail></alias> 
		 <alias><name>Luna</name>

<address>172.16.100.10</address>

			<type>host</type>
			<detail>Entry added Thu, 21 Oct 2010 14:46:21 +0200</detail></alias> 
		 <alias><name>MailPorts</name>

<address>25 110 143 465 587 993 995</address>

			<type>port</type>
			<detail>Entry added Sun, 21 Nov 2010 16:23:51 +0100||Entry added Sun, 21 Nov 2010 16:23:51 +0100||Entry added Sun, 21 Nov 2010 16:23:51 +0100||Entry added Sun, 21 Nov 2010 16:23:51 +0100||Entry added Sun, 21 Nov 2010 16:23:51 +0100||Entry added Sun, 21 Nov 2010 16:23:51 +0100||Entry added Sun, 21 Nov 2010 16:23:51 +0100</detail></alias> 
		 <alias><name>ManagementPorts</name>

<address>22 8443</address>

			<type>port</type>
			<detail>SSH||WebGUI</detail></alias> 
		 <alias><name>MessagingPorts</name>

<address>1863 5222 5223 5190</address>

			<type>port</type>
			<detail>MSN||Jabber||Jabber/WhatsApp/Apple Push/FaceTime||ICQ/AIM</detail></alias> 
		 <alias><name>PenaltyBox</name>

<address>10.0.100.100/30 10.0.100.104/29 10.0.100.112/29 10.0.100.120/32 172.16.100.100/30 172.16.100.104/29 172.16.100.112/29 172.16.100.120/32 192.168.100.100/30 192.168.100.104/29 192.168.100.112/29 192.168.100.120/32</address>

			<type>network</type>
			<detail>Entry added Sun, 05 Dec 2010 20:29:45 +0100||Entry added Sun, 05 Dec 2010 20:29:45 +0100||Entry added Sun, 05 Dec 2010 20:29:45 +0100||Entry added Sun, 05 Dec 2010 20:29:45 +0100||Entry added Sun, 05 Dec 2010 20:29:45 +0100||Entry added Sun, 05 Dec 2010 20:29:45 +0100||Entry added Sun, 05 Dec 2010 20:29:45 +0100||Entry added Sun, 05 Dec 2010 20:29:45 +0100||Entry added Sun, 05 Dec 2010 20:29:45 +0100||Entry added Sun, 05 Dec 2010 20:29:45 +0100||Entry added Sun, 05 Dec 2010 20:29:45 +0100||Entry added Sun, 05 Dec 2010 20:29:45 +0100</detail></alias> 
		 <alias><name>pfSense</name>

<address>10.0.100.254 172.16.100.254 192.168.100.254</address>

			<type>host</type>
			<detail>LAN||WLAN||WLAN-Guest</detail></alias> 
		 <alias><name>Speedport</name>

<address>192.168.2.1</address>

			<type>host</type>
			<detail>Entry added Thu, 21 Oct 2010 22:50:26 +0200</detail></alias> 
		 <alias><name>StarCraft2Ports</name>

<address>1119 3724</address>

			<type>port</type>
			<detail>Battle.net||Entry added Wed, 15 Dec 2010 13:40:47 +0100</detail></alias> 
		 <alias><name>SteamPorts</name>

<address>27000:27015 27015:27030 27014:27050 4380 27015 3478 4379 4380 1500 3005 3101 28960</address>

			<type>port</type>
			<detail>Steam Client UDP 27000 to 27015 inclusive (Game client traffic)||Steam Client UDP 27015 to 27030 inclusive (Typically Matchmaking and HLTV)||Steam Client TCP 27014 to 27050 inclusive (Steam downloads)||Steam Client UDP 4380||Dedicated or Listen Servers TCP 27015 (SRCDS Rcon port)||Steamworks P2P Networking and Steam Voice Chat UDP 3478 (Outbound)||Steamworks P2P Networking and Steam Voice Chat UDP 4379 (Outbound)||Steamworks P2P Networking and Steam Voice Chat UDP 4380 (Outbound)||Additional Ports for Call of Duty: Modern Warfare 2 Multiplayer UDP 1500 (outbound)||Additional Ports for Call of Duty: Modern Warfare 2 Multiplayer UDP 3005 (outbound)||Additional Ports for Call of Duty: Modern Warfare 2 Multiplayer UDP 3101 (outbound)||Additional Ports for Call of Duty: Modern Warfare 2 Multiplayer UDP 28960</detail></alias> 
		 <alias><name>TeamviewerPorts</name>

<address>5938 60179</address>

			<type>port</type>
			<detail>Entry added Wed, 24 Nov 2010 23:15:04 +0100||Entry added Wed, 24 Nov 2010 23:15:04 +0100</detail></alias> 
		 <alias><name>WebPorts</name>

<address>80 443</address>

			<type>port</type>
			<detail>HTTP||HTTPS</detail></alias> 
		 <alias><name>WirelessLocalAreaNetwork</name>

<address>172.16.100.0/24</address>

			<type>network</type>
			<detail>Entry added Thu, 21 Oct 2010 13:27:38 +0200</detail></alias></aliases>

So there definitely is a aliases part…

jimp

The errors you show are more indicative of a filesystem that has been corrupted. On embedded, you may try switching back to the other boot slice. If neither one works, you may have to reflash.

On a full install, you'd need to reinstall from CD but you should be able to use the "Rescue install" option to pull your config from the hard drive (Or just do a fresh install and restore your config as you mentioned)

jlepthien

Aha. So you think my config would work on a new flashed install?

jimp

It might, but if your filesystem is corrupt there is always a chance that something in the config could be corrupt as well.

So while it is more likely to work with a freshly flashed CF, I can't say for certain it would.

jlepthien

So what should you do so that this type of thing does not happen? Test a config restore every now and then?

jimp

Normally it's not a problem over time, just keeping a few backups around may be enough. It may just be that it was corrupted by chance, but the only real test is to restore the config (perhaps in a VM) to see if it works OK.

Testing backups is a good task for any backup plan. Backups can't help you if they aren't usable. :)

jlepthien

True ;-)

Actually I have a VM around with a 2.0 full version…

Will try to restore that one now...

jimp

You can make embedded VMs in either VMWare or VirtualBox as well, though it is a little trickier to setup since you either have to convert the nanobsd image to a virtual disk directly, or attach the target virtual disk to another VM where you can download and use dd inside the VM to pull it off. Both VMWare and VirtualBox support named pipe serial ports you can connect to with putty or another program. It's pretty slick once it's all setup.

jlepthien

Hm. No, that config wouldn't restore in a vm as well :(
I also tested older configs from october. Same error, everytime…
Tried with aliases and nat section. Does not work. Does this restore of some actually work for you in newer builds? Perhaps nobody tried to restore just a part of the config?

jimp

The partial restore doesn't seek out portions of a whole config, you have to edit out the part you want. For example, to restore DHCP settings, you need to cut the <dhcpd>…</dhcpd> section out into a separate file, and then pick that file along with choosing the DHCP server settings from the drop-down.

jlepthien

Aha. So THAT could be the problem….

jlepthien

Thanks jimp! That works! Man I could have searched a long time. Perhaps you should add a comment on the restore page so that everyone knows about this…

Or am I the only one who didn't know how it's suppose to work? ;)

jlepthien

@ermal:

Try this manually
https://rcs.pfsense.org/projects/pfsense/repos/mainline/commits/92a1c8e6caca910ae1f8c54751bffebd45d87682

or wait for a snapshot with the patch applied.

I just had this error while updating my config. Applied this manually and it works. Will check if it reached the newest snap yet…

jlepthien

Ok the fix is in the newest snap, but there seems to be a problem. Each time I reboot my Alix I get the same error as I posted in the beginning of this thread. I then need to ssh into my box do a killall mpd5. Then I have to go into the WebUI to my WAN interface, set a 0 into the idle timeout field and click save. Is this actually also a bug that I have to put in the zero everytime again? It does not get saved somehow…

After these steps my connections stays online until the next reboot...

gnhb

So, are you saying that you have the "Dial on Demand" checkbox checked? Do you really need Dial on Demand?

Refs for devs:
http://redmine.pfsense.org/issues/757

http://redmine.pfsense.org/issues/927

jlepthien

Yes, that box is checked. I want my line to be up and running all the time…

gnhb

Well, two points.

First if you you want your line up and running all the time, you need to uncheck that box. That box is supposed to bring the line down when no outgoing traffic is detected after "Idle timeout" time has elapsed.

Second, checking that box is likely what has caused all your problems. That options invokes some pretty complex code that apparently still isn't stable. (re: linked redmine issues)

grandrivers

If thats is the intended function of dial on demand the the wording of setting it to zero should be remove and replace with untick for always on connection would clear up some confusion

eri--

Can you please test with latest snapshots?