ppp, host route entry via tun interface

rsg7 · Apr 2, 2010

Hello.

The route which created by ppp don't deleted after user disconnection.

I have FreeBSD 7.3 on my VPN server (poptop-1.3.4_2 ) :

Code:

gw03# uname -a
FreeBSD gw03.pvt 7.3-RELEASE FreeBSD 7.3-RELEASE #0: Wed Mar 31 17:55:46 UTC 2010     root@:/usr/obj/usr/src/sys/ESH-GW-20103031  i386

I have 2 users account in ppp.secret:

Code:

gw03# cat /etc/ppp/ppp.secret
first  123456  10.224.36.123
second 123456  10.224.36.124

Code:

gw03# cat /etc/ppp/ppp.conf
<...>
pptp:
 enable chap
 set timeout 0
 set lqrperiod 20
 set echoperiod 20
 enable lqr echo
 set ifaddr 10.0.0.1 10.0.0.2-10.0.0.255 255.255.255.255

When 1st user connected to vpn server I see:

Code:

gw03# ifconfig
<...>
tun0: flags=8051<UP,POINTOPOINT,RUNNING,MULTICAST> metric 0 mtu 1400
        inet 10.0.0.1 --> 10.224.36.123 netmask 0xffffffff
        Opened by PID 2515

Code:

gw03# netstat -rn
Routing tables
<...>
10.224.36.123      10.0.0.1           UGH         0        0   tun0
<...>

When 2nd user connect to vpn server:

Code:

gw03# ifconfig
<...>
tun0: flags=8051<UP,POINTOPOINT,RUNNING,MULTICAST> metric 0 mtu 1400
        inet 10.0.0.1 --> 10.224.36.123 netmask 0xffffffff
        Opened by PID 2515
tun1: flags=8051<UP,POINTOPOINT,RUNNING,MULTICAST> metric 0 mtu 1400
        inet 10.0.0.1 --> 10.224.36.124 netmask 0xffffffff
        Opened by PID 2519

Code:

gw03# netstat -rn
Routing tables
<...>
10.224.36.123      10.0.0.1           UGH         0        0   tun0
10.224.36.124      10.0.0.1           UGH         0        0   tun1
<...>

All work fine. But then begins mysterious behavior.

When 2nd user disconnected from vpn server i can see:

Code:

gw03# ifconfig
tun0: flags=8051<UP,POINTOPOINT,RUNNING,MULTICAST> metric 0 mtu 1400
        inet 10.0.0.1 --> 10.224.36.123 netmask 0xffffffff
        Opened by PID 2515
tun1: flags=8010<POINTOPOINT,MULTICAST> metric 0 mtu 1500

Code:

gw03# netstat -rn
Routing tables
<...>
[B]10.224.36.123      10.0.0.1           UGH         0        0   tun0
10.224.36.124      10.0.0.1           UGH         0        0   tun0[/B]
<...>

WTF? Why route don't deleted from routing table?

Code:

gw03# cat /var/log/ppp.log
<...>
Apr  2 14:26:19 gw03 ppp[2519]: tun1: CCP: deflink: RecvTerminateAck(5) state = Req-Sent
Apr  2 14:26:22 gw03 ppp[2519]: tun1: CCP: deflink: LayerFinish.
Apr  2 14:26:22 gw03 ppp[2519]: tun1: CCP: deflink: State change Req-Sent --> Stopped
Apr  2 14:26:23 gw03 ppp[2519]: tun1: LCP: deflink: RecvTerminateReq(9) state = Opened
Apr  2 14:26:23 gw03 ppp[2519]: tun1: LCP: deflink: LayerDown
Apr  2 14:26:23 gw03 ppp[2519]: tun1: LCP: deflink: SendTerminateAck(9) state = Opened
Apr  2 14:26:23 gw03 ppp[2519]: tun1: LCP: deflink: State change Opened --> Stopping
Apr  2 14:26:23 gw03 ppp[2519]: tun1: CCP: deflink: State change Stopped --> Closed
Apr  2 14:26:23 gw03 ppp[2519]: tun1: CCP: deflink: State change Closed --> Initial
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Phase: deflink: open -> lcp
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Debug: route_UpdateMTU (18)
Apr  2 14:26:23 gw03 ppp[2519]: tun1: IPCP: deflink: LayerDown: 10.0.0.1
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Debug: ReadSystem: Can't open /etc/ppp/ppp.linkdown.
Apr  2 14:26:23 gw03 last message repeated 2 times
Apr  2 14:26:23 gw03 ppp[2519]: tun1: IPCP: deflink: State change Opened --> Starting
Apr  2 14:26:23 gw03 ppp[2519]: tun1: IPCP: deflink: LayerFinish.
Apr  2 14:26:23 gw03 ppp[2519]: tun1: IPCP: Connect time: 16 secs: 1952 octets in, 0 octets out
Apr  2 14:26:23 gw03 ppp[2519]: tun1: IPCP: 16 packets in, 0 packets out
Apr  2 14:26:23 gw03 ppp[2519]: tun1: IPCP:  total 122 bytes/sec, peak 290 bytes/sec on Fri Apr  2 14:26:12 2010
Apr  2 14:26:23 gw03 ppp[2519]: tun1: IPCP: deflink: State change Starting --> Initial
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Phase: bundle: Terminate
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Debug: m_dequeue: queue len = 1
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Phase: deflink: read (0): Got zero bytes
Apr  2 14:26:23 gw03 ppp[2519]: tun1: LCP: deflink: State change Stopping --> Starting
Apr  2 14:26:23 gw03 ppp[2519]: tun1: LCP: deflink: LayerFinish
Apr  2 14:26:23 gw03 ppp[2519]: tun1: LCP: deflink: State change Starting --> Initial
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Phase: deflink: Disconnected!
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Debug: deflink: Close
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Phase: deflink: Connect time: 16 secs: 3622 octets in, 1071 octets out
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Phase: deflink: 36 packets in, 28 packets out
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Phase:  total 293 bytes/sec, peak 1257 bytes/sec on Fri Apr  2 14:26:08 2010
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Phase: deflink: lcp -> closed
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Debug: route_IfDelete (18)
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Phase: bundle: Dead
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Debug: route_UpdateMTU (18)
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Debug: DoLoop done.
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Phase: PPP Terminated (normal).
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Warning: tun1: DIFADDR 10.0.0.1 -> 10.224.36.124 returns 0
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Debug: route_IfDelete (18)
Apr  2 14:26:23 gw03 ppp[2519]: tun1: Debug: Radius: radius_Destroy
<...>

Route deletes from routing table only when first user disconnected.

Code:

gw03# cat /var/log/ppp.log
<...>
Apr  2 14:26:35 gw03 ppp[2515]: tun0: LCP: deflink: RecvTerminateReq(9) state = Opened
Apr  2 14:26:35 gw03 ppp[2515]: tun0: LCP: deflink: LayerDown
Apr  2 14:26:35 gw03 ppp[2515]: tun0: LCP: deflink: SendTerminateAck(9) state = Opened
Apr  2 14:26:35 gw03 ppp[2515]: tun0: LCP: deflink: State change Opened --> Stopping
Apr  2 14:26:35 gw03 ppp[2515]: tun0: CCP: deflink: State change Stopped --> Closed
Apr  2 14:26:35 gw03 ppp[2515]: tun0: CCP: deflink: State change Closed --> Initial
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Phase: deflink: open -> lcp
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: route_UpdateMTU (17)
Apr  2 14:26:35 gw03 ppp[2515]: tun0: IPCP: deflink: LayerDown: 10.0.0.1
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: ReadSystem: Can't open /etc/ppp/ppp.linkdown.
Apr  2 14:26:35 gw03 last message repeated 2 times
Apr  2 14:26:35 gw03 ppp[2515]: tun0: IPCP: deflink: State change Opened --> Starting
Apr  2 14:26:35 gw03 ppp[2515]: tun0: IPCP: deflink: LayerFinish.
Apr  2 14:26:35 gw03 ppp[2515]: tun0: IPCP: Connect time: 44 secs: 2693 octets in, 0 octets out
Apr  2 14:26:35 gw03 ppp[2515]: tun0: IPCP: 22 packets in, 0 packets out
Apr  2 14:26:35 gw03 ppp[2515]: tun0: IPCP:  total 61 bytes/sec, peak 370 bytes/sec on Fri Apr  2 14:25:52 2010
Apr  2 14:26:35 gw03 ppp[2515]: tun0: IPCP: deflink: State change Starting --> Initial
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Phase: bundle: Terminate
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: m_dequeue: queue len = 1
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: link_Dequeue: Dequeued from queue 1, containing 0 more packets
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: deflink: DescriptorWrite: wrote 17(17) to 0
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: deflink: DescriptorRead: read 0/2048 from 0
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Phase: deflink: read (0): Got zero bytes
Apr  2 14:26:35 gw03 ppp[2515]: tun0: LCP: deflink: State change Stopping --> Starting
Apr  2 14:26:35 gw03 ppp[2515]: tun0: LCP: deflink: LayerFinish
Apr  2 14:26:35 gw03 ppp[2515]: tun0: LCP: deflink: State change Starting --> Initial
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Phase: deflink: Disconnected!
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: deflink: Close
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Phase: deflink: Connect time: 44 secs: 4566 octets in, 1147 octets out
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Phase: deflink: 43 packets in, 30 packets out
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Phase:  total 129 bytes/sec, peak 1357 bytes/sec on Fri Apr  2 14:25:52 2010
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Phase: deflink: lcp -> closed
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: route_IfDelete (17)
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: Found 10.224.36.123 10.0.0.1
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: route_IfDelete: Skip it (pass 0)
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: Found 10.224.36.124 10.0.0.1
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: route_IfDelete: Skip it (pass 0)
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: Found 10.224.36.123 10.0.0.1
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: wrote 108: cmd = Delete, dst = 10.224.36.123, gateway = <none>
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: Found 10.224.36.124 10.0.0.1
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: wrote 108: cmd = Delete, dst = 10.224.36.124, gateway = <none>
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Phase: bundle: Dead
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: route_UpdateMTU (17)
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: DoLoop done.
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Phase: PPP Terminated (normal).
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Warning: tun0: DIFADDR 10.0.0.1 -> 10.224.36.123 returns 0
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: route_IfDelete (17)
Apr  2 14:26:35 gw03 ppp[2515]: tun0: Debug: Radius: radius_Destroy

SirDice · Apr 2, 2010

Please use [code] tags for system output.

What do you have in /etc/ppp/ppp.linkup?

rsg7 · Apr 3, 2010

SirDice said:
What do you have in /etc/ppp/ppp.linkup?

I'm not have neither ppp.linkup nor ppp.linkdown. As I know it's not mandatory files.

Code:

gw03# ls -la /etc/ppp/
total 8
drwxr-xr-x   2 root  wheel   512 Apr  3 12:16 .
drwxr-xr-x  20 root  wheel  2048 Apr  1 14:33 ..
-rw-------   1 root  wheel  1361 Apr  2 16:29 ppp.conf
-rw-r--r--   1 root  wheel    58 Apr  2 14:24 ppp.secret

I have the same configuration on my other boxs with FreeBSD 6.4. But on FreeBSD 6.4 all work fine without any problem.

varda · Apr 3, 2010

Try to remove stalled routes forcefully in ppp.linkdown:

Code:

pptp:
 delete! HISADDR

rsg7 · Apr 5, 2010

Many thanks! It's work! Now I try this in production use!

But can anybody say what happened with ppp?

aragon · Apr 5, 2010

Perhaps you should PR this as there were many network changes between 7 and 8, and this might be an unintended regression...

rsg7 · Apr 6, 2010

aragon said:
Perhaps you should PR this

Sorry, what does it mean "PR"?

aragon said:
as there were many network changes between 7 and 8, and this might be an unintended regression...

It seems that "regression" have place between 6 and 7. I didn't try to use 8, but I will do it.

aragon · Apr 6, 2010

rsg7 said:
Sorry, what does it mean "PR"?

Problem Report aka bug report.

rsg7 said:
It seems that "regression" have place between 6 and 7. I didn't try to use 8, but I will do it.

Ah. Best test 8 before reporting anything then.

rsg7 · Apr 12, 2010

I checked the work of ppp on 8.0-STABLE.
All works perfectly except em drivers, but it's another story.

mike_tk · Apr 12, 2010

Faced same problem today. Did anyone posted a PR for this? Any patches exists?
Looks like PR-130159 is other problem, and this problem is 7.3 specific.

rsg7 · Apr 13, 2010

mike_tk said:
Faced same problem today. Did anyone posted a PR for this?

I'm not submitted PR about this issue. You can do this bases on my first post or your own logs.

I'm moved to 8.0-STABLE.

ppp, host route entry via tun interface

Administrator