PPPoE not working on WAN

jader

yes, another thread about this.

O'm a newbie on pfS… using 2.0.1 on Celeron with 1 WAN + 1 LAN .
I have read the previous big thread: Is PPPoE working for you guys? http://forum.pfsense.org/index.php/topic,35475.60.html

I undestand this is a difficult to track issue... so I volunteer to help. I REALLY love to use PPPoE on ADSL modems!

I'm seeing this on /var/log/system.log:


Feb 12 13:31:09 elefante ppp: [wan_link0] Link: reconnection attempt 4
Feb 12 13:31:09 elefante ppp: [wan_link0] PPPoE: Connecting to ''
Feb 12 13:31:18 elefante ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Feb 12 13:31:18 elefante ppp: [wan_link0] Link: DOWN event
Feb 12 13:31:18 elefante ppp: [wan_link0] LCP: Down event
Feb 12 13:31:18 elefante ppp: [wan_link0] Link: reconnection attempt 5 in 2 seconds
CLOGGC|##[2.0-RELEASE][root@elefante#
[/code]

I've tried to use NULL and left NULL checkbox clean... do not work either case.
I've discovered when I change info in Interfaces Assign PPP, pfS still try to use old parameters (have change ServiceName from blank to Jader and syslog still show trying without a name!
I'm not sure how to restart ppp dialer... to force parameters reload... or why it do not make that by himself!

Other useful information:

I have a SME server 8b7 (www.contribs.org) at home, it has 2 NIC (1 LAN + 1WAN in PPPoE mode): it connect 100% all times.
If I just unplug network cable from my SME server and plug on pfS it never connects.

I've seen this same machine fail on another  similar situation: I have one install using a WRT310N with WAN in PPPoE mode. It connect 100% all times.
If I unplug network cable and connect to pfS (this same machine) it never connect.
If I left it plugged and restart pfS... it never connects.
[b]MORE: If I unplug cable from pfS and return it to WRT310N or my home SME8b7 server, it connect in 2 sec!
[/b]

The ISP for both are same: GVT ( a local provider here in Brazil). They are good ISP... but linux support do not exist!
The problem may be a timeout issue ? (hanging up too soon = 9 sec ?)

I just to know it's a pfS2 issue... because three other products can connect (I used to use a IPCOP1.4.x on this machine and was working fine).
I have reformated pfS more than twice... it behave same way all times... same log messages!

any tip is welcome... I'm here to help.

Jáder

wallabybob

@jader:

I'm not sure how to restart ppp dialer… to force parameters reload... or why it do not make that by himself!

Try this: In Interfaces -> WAN clear the Enable box, then click Save (bottom of the page) then tick Enable then click Save.

Or reboot.

jader

@wallabybob:

@jader:

I'm not sure how to restart ppp dialer… to force parameters reload... or why it do not make that by himself!

Try this: In Interfaces -> WAN clear the Enable box, then click Save (bottom of the page) then tick Enable then click Save.

Or reboot.

Ok… learned how to force update parameters... but still do now works.
Any tip about how to discover why it works for a WRT310n / SME8b7 / IPCOP14x but not for pfS2 ??

Jáder

wallabybob

What is immediately upstream of your pfSense WAN interface (an ADSL modem/router? brand ?? model??)?

Is there anything of interest in the pfSense Status -> System Logs - check the System and PPP tabs.

You could take packet captures of your pppoe interface in startup attempt and repeat on the physical interface used by your pppoe interface and post the clearly annotated captures here.

I noticed you say you are using pfSense 2.0.1 but your shell output suggests you are using 2.0. What is displayed in the version field of the pfSense home page? There are some PPP problems in 2.0 that have been reported to be fixed in 2.0.1. It is probably best to make sure you are using 2.0.1 before doing any further analysis.

jader

@wallabybob:

What is immediately upstream of your pfSense WAN interface (an ADSL modem/router? brand ?? model??)?
/quote]
Siemens Speedstream 4200

Is there anything of interest in the pfSense Status -> System Logs - check the System and PPP tabs.

In Status -> System Logs -> PPP there are just same log as seen in system.log:
Feb 12 19:56:01 ppp: [wan_link0] Link: reconnection attempt 229
Feb 12 19:56:01 ppp: [wan_link0] PPPoE: Connecting to ''
Feb 12 19:56:10 ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Feb 12 19:56:10 ppp: [wan_link0] Link: DOWN event
Feb 12 19:56:10 ppp: [wan_link0] LCP: Down event
Feb 12 19:56:10 ppp: [wan_link0] Link: reconnection attempt 230 in 2 seconds

In Status -> System Logs -> System – I can see nothing useful. Lasts entries:
Feb 12 19:55:07 dnsmasq[35242]: started, version 2.55 cachesize 10000
Feb 12 19:55:07 dnsmasq[35242]: compile time options: IPv6 GNU-getopt no-DBus I18N DHCP TFTP
Feb 12 19:55:07 dnsmasq[35242]: reading /etc/resolv.conf
Feb 12 19:55:07 dnsmasq[35242]: ignoring nameserver 127.0.0.1 - local interface
Feb 12 19:55:07 dnsmasq[35242]: ignoring nameserver 127.0.0.1 - local interface
Feb 12 19:55:07 dnsmasq[35242]: read /etc/hosts - 2 addresses
Feb 12 19:55:07 php: /system.php: The command '/usr/bin/killall 'ntpd'' returned exit code '1', the output was 'killall: warning: kill -TERM 44030: No such process'
Feb 12 19:55:07 php: /system.php: OpenNTPD is starting up.
Feb 12 19:55:07 check_reload_status: Rewriting resolv.conf
Feb 12 19:55:07 check_reload_status: Reloading filter
Feb 12 19:55:47 dnsmasq[35242]: reading /etc/resolv.conf
Feb 12 19:55:47 dnsmasq[35242]: ignoring nameserver 127.0.0.1 - local interface

You could take packet captures of your pppoe interface in startup attempt and repeat on the physical interface used by your pppoe interface and post the clearly annotated captures here.

I'm sorry… no idea how to do this... can you elaborate ?

I noticed you say you are using pfSense 2.0.1 but your shell output suggests you are using 2.0. What is displayed in the version field of the pfSense home page? There are some PPP problems in 2.0 that have been reported to be fixed in 2.0.1. It is probably best to make sure you are using 2.0.1 before doing any further analysis.

Hum… that's true... I'm not sure how could update pfS without an external connection... I'll have to reconfigure everything to have a fake internal network and put WAN as part of my network LAN so it can see internet... or change my modem configuration (somehting I'd like to avoid).
Of could I download the update and run on shell or from somewhere in web interface ?

EDIT: Found the manual update ... upload 90MB file right now... I'll try 2.0.1 update in 5 minutes!
EDIT2: nothing changed... I'm still looking for a way to find out what is differnet from my SME8b7 CentOS Linux server and pfS201...
I can do anything to diagnose... have spare time!

jader

Here is log from my SME8b7 server (CentOS based) connecting:

Feb 12 20:34:07 guepardo esmith::event[5039]: Processing event: ip-down ppp0  38400 200.175.213.224 201.22.216.1 pppoe 
Feb 12 20:34:08 guepardo pppd[4129]: Script /etc/ppp/ip-down finished (pid 5027), status = 0x0
Feb 12 20:34:08 guepardo pppd[4129]: Exit.
Feb 12 20:34:08 guepardo pppd[5227]: pppd 2.4.4 started by root, uid 0
Feb 12 20:34:08 guepardo pppd[5227]: using channel 404
Feb 12 20:34:08 guepardo pppd[5227]: Using interface ppp0
Feb 12 20:34:08 guepardo pppd[5227]: Connect: ppp0 <--> /dev/pts/0
Feb 12 20:34:09 guepardo pppoe[5236]: PADS: Service-Name: ''
Feb 12 20:34:09 guepardo pppoe[5236]: PPP session is 8937
Feb 12 20:34:09 guepardo pppd[5227]: sent [LCP ConfReq id=0x1 <mru 1492=""><magic 0x2171802="">]
Feb 12 20:34:09 guepardo pppd[5227]: rcvd [LCP ConfReq id=0x4 <mru 1492=""><auth pap=""><magic 0x257db3e4="">]
Feb 12 20:34:09 guepardo pppd[5227]: sent [LCP ConfAck id=0x4 <mru 1492=""><auth pap=""><magic 0x257db3e4="">]
Feb 12 20:34:09 guepardo pppd[5227]: rcvd [LCP ConfAck id=0x1 <mru 1492=""><magic 0x2171802="">]
Feb 12 20:34:09 guepardo pppd[5227]: sent [LCP EchoReq id=0x0 magic=0x2171802]
Feb 12 20:34:09 guepardo pppd[5227]: sent [PAP AuthReq id=0x1 user="turbonet@turbonet" password=<hidden>]
Feb 12 20:34:09 guepardo pppd[5227]: rcvd [LCP EchoRep id=0x0 magic=0x257db3e4]
Feb 12 20:34:10 guepardo pppd[5227]: rcvd [PAP AuthAck id=0x1 ""]
Feb 12 20:34:10 guepardo pppd[5227]: PAP authentication succeeded
Feb 12 20:34:10 guepardo pppd[5227]: sent [IPCP ConfReq id=0x1 <addr 200.175.213.224="">]
Feb 12 20:34:10 guepardo pppd[5227]: rcvd [IPCP ConfNak id=0x1 <addr 201.86.244.20="">]
Feb 12 20:34:10 guepardo pppd[5227]: sent [IPCP ConfReq id=0x2 <addr 201.86.244.20="">]
Feb 12 20:34:10 guepardo pppd[5227]: rcvd [IPCP ConfAck id=0x2 <addr 201.86.244.20="">]
Feb 12 20:34:10 guepardo pppd[5227]: rcvd [IPCP ConfReq id=0xaf <addr 201.22.216.1="">]
Feb 12 20:34:10 guepardo pppd[5227]: sent [IPCP ConfAck id=0xaf <addr 201.22.216.1="">]
Feb 12 20:34:10 guepardo pppd[5227]: local  IP address 201.86.244.20
Feb 12 20:34:10 guepardo pppd[5227]: remote IP address 201.22.216.1</addr></addr></addr></addr></addr></addr></hidden></magic></mru></magic></auth></mru></magic></auth></mru></magic></mru>

wallabybob

The log of PPPoE successful startup on SME could be useful for comparison.

One way of packet capture: ssh into pfsense as admin, select option 8 (Shell), give shell command

tcpdump -i pppoe0 -c 20 -e -n -vvv

which will display packets sent and received on interface pppoe0 (change to suit your configuration), display 20 packets then exit, don't translate IP addresses to names, display link headers, extensive decode of contents.

Repeat for the physical interface PPPoE is using.

It could be useful talking with tech support at your ISP - are they seeing PPP startup attempts from you?

Does you modem show any indication of forwarding PPP startups from you? (Does it have packet capture? log? interface counters?)

jader

@wallabybob:

One way of packet capture: ssh into pfsense as admin, select option 8 (Shell), give shell command

tcpdump -i pppoe0 -c 20 -e -n -vvv

which will display packets sent and received on interface pppoe0 (change to suit your configuration), display 20 packets then exit, don't translate IP addresses to names, display link headers, extensive decode of contents.

Repeat for the physical interface PPPoE is using.

It could be useful talking with tech support at your ISP - are they seeing PPP startup attempts from you?

Does you modem show any indication of forwarding PPP startups from you? (Does it have packet capture? log? interface counters?)

NOW THAT'S STRANGE… I got nothing from both of them (vr0 = physical network & pppoe0 ) when seen thru tcpdump!
My modem has a light for DSL, it blinks when data flow... I can see it blinking shortly on each pppoe attempt.
Otherwise I have no access to modem, it's on bridged mode. Maybe I should reset it, put it on default router mode, add a second NIC as seen other place to talk directly to modem and start over.
Again... I prefer do not mess with my modem configuration... but if there are no other way...

wallabybob

@jader:

Otherwise I have no access to modem, it's on bridged mode.

I followed [urlhttp://doc.pfsense.org/index.php/Accessing_modem_from_inside_firewall] to access the web GUI of my Tenda D820B ADSL modem. My modem has some very basic interface statistics - perhaps your modem will be a bit more informative.

@jader:

NOW THAT'S STRANGE… I got nothing from both of them (vr0 = physical network & pppoe0 ) when seen thru tcpdump!
My modem has a light for DSL, it blinks when data flow... I can see it blinking shortly on each pppoe attempt.

I don't know how you can be certain that the modem blinks on each pppoe attempt.

It would be quite strange for ppp to be reporting its attempting a connection and a tcpdump of the ppp interface and the underlying physical interface both reporting no traffic. At this point I probably need to defer to someone who knows more about the details of the ppp implementation.

jader

@wallabybob:

@jader:

Otherwise I have no access to modem, it's on bridged mode.

I followed [urlhttp://doc.pfsense.org/index.php/Accessing_modem_from_inside_firewall] to access the web GUI of my Tenda D820B ADSL modem. My modem has some very basic interface statistics - perhaps your modem will be a bit more informative.

Ok… I'll try later. I got a new idea... maybe my vr0 (via card) is unable to switch to promiscuous mode to capture packets.
So I replaced it with a Realtek 8139 and saw this on system.log:
Feb 13 08:41:43 elefante ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Feb 13 08:41:43 elefante ppp: [wan_link0] Link: DOWN event
Feb 13 08:41:43 elefante ppp: [wan_link0] LCP: Down event
Feb 13 08:41:43 elefante ppp: [wan_link0] Link: reconnection attempt 2 in 1 seconds
Feb 13 08:41:44 elefante ppp: [wan_link0] Link: reconnection attempt 2
Feb 13 08:41:44 elefante ppp: [wan_link0] PPPoE: Connecting to ''

Feb 13 08:41:48 elefante ppp: PPPoE: rec'd ACNAME "srv"

Feb 13 08:41:48 elefante kernel: rl0: watchdog timeout
Feb 13 08:41:48 elefante kernel: ng_pppoe[27]: no matching session
Feb 13 08:41:48 elefante kernel: ng_pppoe[27]: no matching session
Feb 13 08:41:48 elefante kernel: ng_pppoe[27]: no matching session
Feb 13 08:41:53 elefante ppp: [wan_link0] PPPoE connection timeout after 9 seconds
Feb 13 08:41:53 elefante ppp: [wan_link0] Link: DOWN event
Feb 13 08:41:53 elefante ppp: [wan_link0] LCP: Down event
Note the line with one blank line before/after … I put one blank line before/after to be easier to you find it.
My pfS had comunicated with ISP!

Very happy I decided try to capture packets. On pppoe0 interface, got nothing
but on rl0 I can see:

[2.0.1-RELEASE][root@elefante.antinsect.com.br]/root(2): tcpdump -e -n -vvv -i rl0 -c 20
tcpdump: WARNING: rl0: no IPv4 address assigned
tcpdump: listening on rl0, link-type EN10MB (Ethernet), capture size 96 bytes
08:46:57.045495 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0x80320EC5] [Service-Name]
08:46:59.074116 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0x80320EC5] [Service-Name]
08:47:03.130116 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0x80320EC5] [Service-Name]
08:47:07.642785 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0x80320EC5] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:07.642923 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0x80320EC5] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:07.643015 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0x80320EC5] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:09.173812 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0xC0370EC5] [Service-Name]
08:47:11.202489 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0xC0370EC5] [Service-Name]
08:47:15.255979 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0xC0370EC5] [Service-Name]
08:47:19.850802 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0xC0370EC5] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:19.850942 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0xC0370EC5] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:19.851034 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0xC0370EC5] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:22.351218 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0x402EDDC4] [Service-Name]
08:47:24.380325 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0x402EDDC4] [Service-Name]
08:47:28.417254 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0x402EDDC4] [Service-Name]
08:47:33.080793 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0x402EDDC4] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:33.080949 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0x402EDDC4] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:33.081027 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0x402EDDC4] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:35.531449 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0xC0290EC5] [Service-Name]
08:47:35.531548 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0xC0290EC5] [Service-Name]
20 packets captured
20 packets received by filter
0 packets dropped by kernel

So we moved 1 small step FORWARD…

I'm seeing this error message on console:

rl0: watchdog timeout

So it appears to be timing… a slow answer from ISP maybe... can I increase time before timeout ?

Regards

Jáder

PS: I'll try to access my modem later... now it's gym time! I'll be back in 2h.

wallabybob

@jader:

maybe my vr0 (via card) is unable to switch to promiscuous mode to capture packets.

Unlikely. vr0 on both my pfSense boxes has no trouble going into promiscuous mode for packet capture.

@jader:

So I replaced it with a Realtek 8139 and saw this on system.log:
. . .
My pfS had comunicated with ISP!

Good you got a response: I'm not familiar enough with PPP to interpret the response.

@jader:

but on rl0 I can see:

[2.0.1-RELEASE][root@elefante.antinsect.com.br]/root(2): tcpdump -e -n -vvv -i rl0 -c 20
tcpdump: WARNING: rl0: no IPv4 address assigned
tcpdump: listening on rl0, link-type EN10MB (Ethernet), capture size 96 bytes
08:46:57.045495 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0x80320EC5] [Service-Name]
08:46:59.074116 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0x80320EC5] [Service-Name]
08:47:03.130116 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0x80320EC5] [Service-Name]
08:47:07.642785 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0x80320EC5] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:07.642923 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0x80320EC5] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:07.643015 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0x80320EC5] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:09.173812 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0xC0370EC5] [Service-Name]
08:47:11.202489 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0xC0370EC5] [Service-Name]
08:47:15.255979 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0xC0370EC5] [Service-Name]
08:47:19.850802 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0xC0370EC5] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:19.850942 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0xC0370EC5] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:19.851034 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0xC0370EC5] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:22.351218 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0x402EDDC4] [Service-Name]
08:47:24.380325 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0x402EDDC4] [Service-Name]
08:47:28.417254 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0x402EDDC4] [Service-Name]
08:47:33.080793 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0x402EDDC4] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:33.080949 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0x402EDDC4] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:33.081027 00:90:1a:a1:c5:00 > 00:06:4f:39:9f:b7, ethertype PPPoE D (0x8863), length 60: PPPoE PADO [AC-Name "srv"] [Host-Uniq 0x402EDDC4] [Service-Name] [AC-Cookie 0x1A9A7276139F1575893DE70D9C03C52B]
08:47:35.531449 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0xC0290EC5] [Service-Name]
08:47:35.531548 00:06:4f:39:9f:b7 > ff:ff:ff:ff:ff:ff, ethertype PPPoE D (0x8863), length 60: PPPoE PADI [Host-Uniq 0xC0290EC5] [Service-Name]
20 packets captured
20 packets received by filter
0 packets dropped by kernel

The trace shows three sequences of pfSense sending 3 PADIs with multi-second intervals between each. Then very soon after the third PADI three PADOs are returned with a very small interval between them. I wonder if the tcpdump displays the time the packet is given to the driver rather than the time the driver receives notification the packet has been transmitted and the three PADIs are sent in very quick succession some time after the driver gets the third one, consequently the three PADOs are returned in quick succession. It would need some sort of packet capture in the modem or on the wire to get a more accurate understanding of what is really going on.

@jader:

I'm seeing this error message on console:

rl0: watchdog timeout

So it appears to be timing… a slow answer from ISP maybe... can I increase time before timeout ?

I haven't looked into the specifics for the rl driver but watchdog timeout from some NIC drivers means the watchdog timer started on transmission initiation expired before the driver got notification of completion of transmission.

I wonder if pfSense failed to negotiate the correct link parameters for its conversation with the modem.

jader

Unlikely. vr0 on both my pfSense boxes has no trouble going into promiscuous mode for packet capture.

so ity's a bad NIC?

The trace shows three sequences of pfSense sending 3 PADIs with multi-second intervals between each. Then very soon after the third PADI three PADOs are returned with a very small interval between them. I wonder if the tcpdump displays the time the packet is given to the driver rather than the time the driver receives notification the packet has been transmitted and the three PADIs are sent in very quick succession some time after the driver gets the third one, consequently the three PADOs are returned in quick succession. It would need some sort of packet capture in the modem or on the wire to get a more accurate understanding of what is really going on.

I'll try to access modem directly to see from his perspective.

I haven't looked into the specifics for the rl driver but watchdog timeout from some NIC drivers means the watchdog timer started on transmission initiation expired before the driver got notification of completion of transmission.

I wonder if pfSense failed to negotiate the correct link parameters for its conversation with the modem.

hum… how I can debug this?
How can I increase log verbosity / timeout time?

jader

SOLVED SOLVED SOLVED
quick answer: disable ACPI on boot choosing option 2!

Later follow http://doc.pfsense.org/index.php/Booting_Options#Disabling_ACPI to make it permanent.

long history:
I was having another problems with that machine… and it was not production yet... so I started to debug.
I was worried about how slow it was!
I was worried about error messages about timeout and missing interrupts on NICs.
I was worried about PPPoE do not work JUST FOR ME ... and I REALLLY WANNA TO HAVE PPPoE to avoid double NAT!
So I started to change settings / replace items!

I replate 2 NICs twice
I replace all CABLES involved
I replace ADSL modem

nothing helps.
I choose DHCP to WAN and discovered my future pfSense2 firewall was taking 1 minute to get an IP from modem... on a direct connection.
So... should be something on machine...not in pfS2, not in other HW (NIC, cable, modem).

With that information was easy... my first tought was to disable ACPI... a long history of problems with it (never one had included this sintoms!)
in just one minute I was a HAPPY user!

Now I'll SCREAM this in ANY forum I can find SOMEONE with PPPoE problem... it's a simple and quick test!!!