PPPoE (STABLE 5) : two PADI packets emitted and then nothing...

[ComteZero _]

here is ppp.log in plain text :

here is ppp.log :
Sep 11 19:42:17 fidelio ppp[24723]: Phase: Using interface: tun0
Sep 11 19:42:17 fidelio ppp[24723]: Phase: deflink: Created in closed state
Sep 11 19:42:17 fidelio ppp[24723]: tun0: Command: default: set ifaddr 
X.X.X.X/0 10.0.0.2/0 <http://10.0.0.2/0>
Sep 11 19:42:17 fidelio ppp[24723]: tun0: Phase: PPP Started (interactive 
mode).
Sep 11 19:42:17 fidelio ppp[24723]: tun0: Timer: prompt /dev/ttyv0: fdset(r) 
0
Sep 11 19:42:23 fidelio ppp[24723]: tun0: Timer: Select returns 1
Sep 11 19:42:23 fidelio ppp[24723]: tun0: Command: /dev/ttyv0: load MY_ISP
Sep 11 19:42:23 fidelio ppp[24723]: tun0: ID0: 0x282e97c0 = 
fopen("/etc/ppp/ppp.conf", "r")
Sep 11 19:42:23 fidelio ppp[24723]: tun0: Debug: ReadSystem: Checking 
default (/etc/ppp/ppp.conf).
Sep 11 19:42:23 fidelio ppp[24723]: tun0: ID0: 0x282e97c0 = 
fopen("/etc/ppp/ppp.conf", "r")
Sep 11 19:42:23 fidelio ppp[24723]: tun0: Debug: ReadSystem: Checking MY_ISP 
(/etc/ppp/ppp.conf).
Sep 11 19:42:23 fidelio ppp[24723]: tun0: ID0: 0x282e97c0 = 
fopen("/etc/ppp/ppp.conf", "r")
Sep 11 19:42:23 fidelio ppp[24723]: tun0: Debug: ReadSystem: Checking MY_ISP 
(/etc/ppp/ppp.conf).
Sep 11 19:42:23 fidelio ppp[24723]: tun0: Command: easyconnect: set device 
PPPoE:xl0
Sep 11 19:42:23 fidelio ppp[24723]: tun0: Command: easyconnect: set authname 
MY_USER
Sep 11 19:42:23 fidelio ppp[24723]: tun0: Command: easyconnect: set authkey 
********
Sep 11 19:42:23 fidelio ppp[24723]: tun0: Command: easyconnect: set dial
Sep 11 19:42:23 fidelio ppp[24723]: tun0: Command: easyconnect: add default 
HISADDR
Sep 11 19:42:23 fidelio ppp[24723]: tun0: ID0: 3 = socket(17, 3, 0)
Sep 11 19:42:23 fidelio ppp[24723]: tun0: ID0: -1 = write(3, data, 140)
Sep 11 19:42:23 fidelio ppp[24723]: tun0: TCP/IP: rt_Set failure:
Sep 11 19:42:23 fidelio ppp[24723]: tun0: TCP/IP: rt_Set: Cmd = Add
Sep 11 19:42:23 fidelio ppp[24723]: tun0: TCP/IP: rt_Set: Dst =
0.0.0.0/0<http://0.0.0.0/0>
Sep 11 19:42:23 fidelio ppp[24723]: tun0: TCP/IP: rt_Set: Gateway =
10.0.0.2<http://10.0.0.2>
Sep 11 19:42:23 fidelio ppp[24723]: tun0: Debug: wrote -1: cmd = Add, dst = 
0.0.0.0/0 <http://0.0.0.0/0>, gateway = 10.0.0.2 <http://10.0.0.2>
Sep 11 19:42:23 fidelio ppp[24723]: tun0: Timer: prompt /dev/ttyv0: fdset(r) 
0
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Timer: Select returns 1
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Command: /dev/ttyv0: dial
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Phase: bundle: Establish
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Phase: deflink: closed -> opening
Sep 11 19:42:26 fidelio ppp[24723]: tun0: ID0: 0 = NgMkSockNode("", &cs, 
&ds)
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Debug: List of netgraph node 
``xl0:'' (id 2) hooks:
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Debug: Found orphans -> ethernet
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Debug: Connecting netgraph socket 
.:tun0 -> [4]::tun0
Sep 11 19:42:26 fidelio ppp[24723]: tun0: ID0: 4 = socket(2, 2, 0)
Sep 11 19:42:26 fidelio ppp[24723]: tun0: ID0: 0 = ioctl(4, 3223349521, 
0xbfbfdd90)
Sep 11 19:42:26 fidelio ppp[24723]: tun0: ID0: 0 = ioctl(4, 2149607696, 
0xbfbfdd90)
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Debug: Sending PPPOE_CONNECT to 
.:tun0
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Debug: Found the following 
interfaces:
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Debug: Index 1, name "fxp0"
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Debug: Index 2, name "xl0"
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Debug: Index 3, name "plip0"
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Debug: Index 4, name "lo0"
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Debug: Index 5, name "tun0"
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Timer: timer_Start: Inserting 
physical throughput timer[0x80be068]
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Phase: deflink: Connected!
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Phase: deflink: opening -> dial
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Chat: deflink: Dial attempt 1 of 1
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Phase: deflink: dial -> carrier
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Debug: Waiting for carrier
Sep 11 19:42:26 fidelio ppp[24723]: tun0: Timer: prompt /dev/ttyv0: fdset(r) 
0
Sep 11 19:42:27 fidelio ppp[24723]: tun0: Timer: Select returns -1
Sep 11 19:42:27 fidelio ppp[24723]: tun0: Timer: ---- Begin of Timer Service 
List---
Sep 11 19:42:27 fidelio ppp[24723]: tun0: Timer: physical throughput 
timer[0x80be068]: freq = 1.00s, next = 0.00s, state = running
Sep 11 19:42:27 fidelio ppp[24723]: tun0: Timer: ---- End of Timer Service 
List ---
Sep 11 19:42:27 fidelio ppp[24723]: tun0: Timer: timer_Start: Inserting 
physical throughput timer[0x80be068]
Sep 11 19:42:27 fidelio ppp[24723]: tun0: Debug: Waiting for carrier
Sep 11 19:42:27 fidelio ppp[24723]: tun0: Timer: prompt /dev/ttyv0: fdset(r) 
0
Sep 11 19:42:28 fidelio ppp[24723]: tun0: Timer: Select returns -1
Sep 11 19:42:28 fidelio ppp[24723]: tun0: Timer: ---- Begin of Timer Service 
List---
Sep 11 19:42:28 fidelio ppp[24723]: tun0: Timer: physical throughput 
timer[0x80be068]: freq = 1.00s, next = 0.00s, state = running
Sep 11 19:42:28 fidelio ppp[24723]: tun0: Timer: ---- End of Timer Service 
List ---
Sep 11 19:42:28 fidelio ppp[24723]: tun0: Timer: timer_Start: Inserting 
physical throughput timer[0x80be068]
Sep 11 19:42:28 fidelio ppp[24723]: tun0: Debug: Waiting for carrier
Sep 11 19:42:28 fidelio ppp[24723]: tun0: Timer: prompt /dev/ttyv0: fdset(r) 
0
Sep 11 19:42:29 fidelio ppp[24723]: tun0: Timer: Select returns -1
Sep 11 19:42:29 fidelio ppp[24723]: tun0: Timer: ---- Begin of Timer Service 
List---
Sep 11 19:42:29 fidelio ppp[24723]: tun0: Timer: physical throughput 
timer[0x80be068]: freq = 1.00s, next = 0.00s, state = running
Sep 11 19:42:29 fidelio ppp[24723]: tun0: Timer: ---- End of Timer Service 
List ---
Sep 11 19:42:29 fidelio ppp[24723]: tun0: Timer: timer_Start: Inserting 
physical throughput timer[0x80be068]
Sep 11 19:42:29 fidelio ppp[24723]: tun0: Debug: Waiting for carrier
Sep 11 19:42:29 fidelio ppp[24723]: tun0: Timer: prompt /dev/ttyv0: fdset(r) 
0
Sep 11 19:42:30 fidelio ppp[24723]: tun0: Timer: Select returns -1
Sep 11 19:42:30 fidelio ppp[24723]: tun0: Timer: ---- Begin of Timer Service 
List---
Sep 11 19:42:30 fidelio ppp[24723]: tun0: Timer: physical throughput 
timer[0x80be068]: freq = 1.00s, next = 0.00s, state = running
Sep 11 19:42:30 fidelio ppp[24723]: tun0: Timer: ---- End of Timer Service 
List ---
Sep 11 19:42:30 fidelio ppp[24723]: tun0: Timer: timer_Start: Inserting 
physical throughput timer[0x80be068]
Sep 11 19:42:30 fidelio ppp[24723]: tun0: Debug: Waiting for carrier
Sep 11 19:42:30 fidelio ppp[24723]: tun0: Timer: prompt /dev/ttyv0: fdset(r) 
0
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Timer: Select returns -1
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Timer: ---- Begin of Timer Service 
List---
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Timer: physical throughput 
timer[0x80be068]: freq = 1.00s, next = 0.00s, state = running
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Timer: ---- End of Timer Service 
List ---
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Timer: timer_Start: Inserting 
physical throughput timer[0x80be068]
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Phase: deflink: Disconnected!
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Phase: deflink: carrier -> hangup
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Debug: deflink: Close
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Phase: deflink: Connect time: 5 
secs: 0 octets in, 0 octets out
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Phase: deflink: 0 packets in, 0 
packets out
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Phase: total 0 bytes/sec, peak 0 
bytes/sec on Sun Sep 11 19:42:26 2005
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Phase: deflink: hangup -> closed
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Debug: route_IfDelete (5)
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Debug: Found ff02:5::/32 
fe80:5::208:c7ff:fe7f:7535
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Debug: route_IfDelete: Skip it 
(pass 0)
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Debug: Found ff02:5::/32 
fe80:5::208:c7ff:fe7f:7535
Sep 11 19:42:31 fidelio ppp[24723]: tun0: ID0: 2 = socket(17, 3, 0)
Sep 11 19:42:31 fidelio ppp[24723]: tun0: ID0: 148 = write(2, data, 148)
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Debug: wrote 148: cmd = Delete, 
dst = ff02:5::/32, gateway = <none>
Sep 11 19:42:31 fidelio ppp[24723]: tun0: ID0: 2 = socket(2, 2, 0)
Sep 11 19:42:31 fidelio ppp[24723]: tun0: ID0: 0 = ioctl(2, 3223349521, 
0xbfbfe970)
Sep 11 19:42:31 fidelio ppp[24723]: tun0: ID0: 0 = ioctl(2, 2149607696, 
0xbfbfe970)
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Phase: bundle: Dead
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Timer: timer_Start: Inserting dial 
timer[0x80bcd44]
Sep 11 19:42:31 fidelio ppp[24723]: tun0: Timer: prompt /dev/ttyv0: fdset(r) 
0


On 9/14/05, ComteZero _ <comte0 at gmail.com> wrote:
> 
> Hello,
> 
> I already posted this thread in freebsd-stable but seems that this list is 
> more appropriate.
> 
> it's been two weeks I try to find out what's wrong. Clean install from 
> cvsup STABLE (5).
> my ADSL account works fine with REL. 4.4+rp_pppoe but not with my new 
> STABLE (5) (without using rp_pppoe).
> could someone help me on this issue (logs provided here, ppp.log in 
> attached file)... 
> two PADI are emitted but nothing happens after.
> (i saw that someone had a similar problem, but with previous netgraph 
> revisions).
> 
> thank you.
> 
> Since my ADSL modem is 3Com HomeConnect, I've set the 
> net.graph.nonstandard_pppoe=1
> 
> ng_pppoe.c rev. is 1.67.2.1 <http://1.67.2.1/>
> ng_socket.c rev. is 1.53.2.3 <http://1.53.2.3/>
> 
> my ppp.conf is :
> default:
> set log all
> set ifaddr X.X.X.X/0 10.0.0.2/0 <http://10.0.0.2/0>
> 
> my_isp :
> set device PPPoE:xl0
> set authname MY_USER
> set authkey MY_PWD
> set dial
> #set login
> add default HISADDR
> 
> 
> here is a tcpdump -vv -i xl0 :
> 
> 18:48:40.808687 PPPoE PADI [Host-Uniq 0x00E654C1]
> 18:48:42.807533 PPPoE PADI [Host-Uniq 0x00E654C1]
> 18:51:44.010839 PPPoE PADI [Host-Uniq 0x40F195C1]
> 18:51:46.009639 PPPoE PADI [Host-Uniq 0x40F195C1]
>  
> thx for your comments.
>  
>