PPPoE issue with CURRENT and 3com ADSL Modem

ComteZero _ comte0 at gmail.com
Sun Sep 11 11:30:09 PDT 2005 

Hello,

it's been two weeks I try to find out what's wrong. Clean install from cvsup 
CURRENT (5).
my ADSL account works fine with REL. 4.4 but not with my new CURRENT (5)
could someone help me on this issue (logs provided here) ?
(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]


here is my 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 
easyconnect (/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 
easyconnect (/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

Thx,

More information about the freebsd-current mailing list