Date: Fri, 18 Mar 2011 20:44:23 +1000 From: Da Rock <freebsd-net@herveybayaustralia.com.au> To: freebsd-net@freebsd.org Subject: Re: mpd- no ng_l2tp coming up Message-ID: <4D833787.3020706@herveybayaustralia.com.au> In-Reply-To: <4D81AE1E.5070103@herveybayaustralia.com.au> References: <4D8164CA.80501@herveybayaustralia.com.au> <4D81871B.1030506@sentex.net> <4D81AE1E.5070103@herveybayaustralia.com.au>
next in thread | previous in thread | raw e-mail | index | archive | help
On 03/17/11 16:45, Da Rock wrote:
> On 03/17/11 13:59, Mike Tancsa wrote:
>> On 3/16/2011 9:32 PM, Da Rock wrote:
>>> I'm running into all sorts of issues setting up l2tp networking. I
>>> think
>>> I have the IPSEC part worked out, but testing parts at a time l2tp dies
>>> in a hole.
>> Try without IPSEC first to make sure you have the l2tp portion correct.
>> Also, make sure no firewall rules are getting in the way.
> Check the last note- local net only atm for testing, though the result
> is the same through the firewall and on the public net. IPSEC works (I
> think), but has been bypassed to resolve the l2tp issues anyway. So
> the only thing between the server and client is the local network.
>> I have this simple mpd5 config file to act as an l2tp server in my test
>> environment
>>
>>
>> startup:
>> # configure mpd users
>> set user admin xxx admin
>> # configure the console
>> set console self 127.0.0.1 5005
>> set console open
>> # configure the web server
>> set web self 192.168.255.254 5006
>> set web open
>> log +IPV6CP
>> log +IPV6CP2
>>
>> default:
>> load l2tpserver
>>
>>
>>
>> l2tpserver:
>> # Define dynamic IP address pool.
>> set ippool add pool1 xx.159.245.1 xx.159.245.5
>> set ippool add pool1 10.241.241.20 10.241.241.99
>> set ippool add rfc1918 172.11.22.140 172.11.22.180
>>
>>
>>
>> # Create clonable bundle template named B
>> create bundle template B
>> set iface idle 1800
>> set iface enable tcpmssfix
>> set ipcp disable vjcomp
>> set bundle enable ipv6cp
>> set ipcp deny vjcomp
>> set ipcp ranges xx.43.128.6/32 ippool pool1
>> set ipcp dns yy.211.164.51 zz.212.134.12
>> #set ipcp nbns 127.0.0.1
>> # Set bundle template to use
>> create link template L l2tp
>> set l2tp hostname sentex
>> set l2tp disable dataseq
>> set link action bundle B
>> # Enable peer authentication
>> set link disable eap
>> set link enable pap
>> set link disable acfcomp
>> set link disable protocomp
>> set link disable check-magic
>> set link deny acfcomp
>> set link keep-alive 10 60
>> set link deny protocomp
>> #load radius
>> set link mtu 1492
>> set link mru 1492
>> set link enable incoming
>> set link disable peer-as-calling
>>
>>
>>
>>
>> For the client, mpd5 works with the following config
>>
>> l2tp_client:
>> #
>> # PPPoE client: only outgoing calls, auto reconnect,
>> # ipcp-negotiated address, one-sided authentication,
>> # default route points on ISP's end
>> #
>>
>> create bundle static B1
>> set iface route default
>> set ipcp ranges 0.0.0.0/0 0.0.0.0/0
>>
>> create link static L1 l2tp
>> set link action bundle B1
>> set auth authname testaccount-in-mpd-secret-file
>> set auth password thepass
>> set link max-redial 0
>> set link mtu 1460
>> set link keep-alive 20 75
>> set l2tp peer 64.7.128.195
>> open
>>
>>
>>> I also had an unscheduled reboot (power failure) and that showed up a
>>> warning: "attempt to domain_add(netgraph) after domainfinalize()" which
>>> I could never quite figure was fatal or not.
>> Thats ok. Its not an issue and is more informational than anything
> Ok. So then my main question is going to be: when should I see a ng
> node through ifconfig? Is it "enabled" (for want of a better term)
> when the server is started, or once a connection is established? Is it
> the same for mpd4 and mpd5?
>
> And shouldn't I see something in the nglist as well?
>>> It appears the control connection is setup and then fails for some
>>> inexplicable reason. The client (android) logs show the same, but it is
>>> definitely the server that kills the connection. Anything I've missed?
>> Make sure there are no firewall rules getting in the way. And if
>> possible, use a client that you know "works". The above server works
>> with Windows clients with IPSEC disabled. Start there, or with a
>> FreeBSD client.
>>
> Windows "works"? Interesting premise :) Sorry, can't help myself...
>
> I have now only got a "clean" network- FBSD only ;) so I'll have to
> try with an mpd client then.
>
> Thanks Mike, I'll be back with some more results soon- it will take
> time to install mpd.
Ok, the results are in.
Client ngctl list:
There are 22 total nodes:
Name: <unnamed> Type: ksocket ID: 00000040 Num hooks: 1
Name: <unnamed> Type: l2tp ID: 0000003e Num hooks: 2
Name: <unnamed> Type: socket ID: 0000003d Num hooks: 1
Name: <unnamed> Type: ksocket ID: 0000003c Num hooks: 1
Name: <unnamed> Type: l2tp ID: 0000003a Num hooks: 2
Name: <unnamed> Type: socket ID: 00000039 Num hooks: 1
Name: <unnamed> Type: ksocket ID: 00000038 Num hooks: 1
Name: <unnamed> Type: l2tp ID: 00000036 Num hooks: 2
Name: <unnamed> Type: socket ID: 00000035 Num hooks: 1
Name: <unnamed> Type: ksocket ID: 00000034 Num hooks: 1
Name: <unnamed> Type: l2tp ID: 00000032 Num hooks: 2
Name: <unnamed> Type: socket ID: 00000031 Num hooks: 1
Name: <unnamed> Type: ksocket ID: 00000030 Num hooks: 1
Name: <unnamed> Type: l2tp ID: 0000002e Num hooks: 2
Name: <unnamed> Type: socket ID: 0000002d Num hooks: 1
Name: ng0 Type: iface ID: 00000006 Num hooks: 0
Name: ngctl20532 Type: socket ID: 00000041 Num hooks: 0
Name: mpd20448-cso Type: socket ID: 00000004 Num hooks: 0
Name: mpd20448-eso Type: socket ID: 00000005 Num hooks: 0
Name: mpd20448-lso Type: socket ID: 00000003 Num hooks: 2
Name: mpd20448-B1 Type: ppp ID: 00000007 Num hooks: 1
Name: mpd20448-L1-lt Type: tee ID: 00000008 Num hooks: 1
So the connection appears to be there, but no network. Ifconfig shows an
ng0 iface with no ip, and netstat shows an unchanged network route.
The server looks like this in ngctl:
There are 10 total nodes:
Name: <unnamed> Type: ksocket ID: 000000a6 Num hooks: 1
Name: <unnamed> Type: l2tp ID: 000000a4 Num hooks: 2
Name: <unnamed> Type: socket ID: 000000a3 Num hooks: 1
Name: <unnamed> Type: ksocket ID: 000000a2 Num hooks: 1
Name: <unnamed> Type: l2tp ID: 000000a0 Num hooks: 2
Name: <unnamed> Type: socket ID: 0000009f Num hooks: 1
Name: mpd4493-cso Type: socket ID: 00000048 Num hooks: 0
Name: mpd4493-eso Type: socket ID: 00000049 Num hooks: 0
Name: mpd4493-lso Type: socket ID: 00000047 Num hooks: 0
Name: ngctl8798 Type: socket ID: 000000a7 Num hooks: 0
Ifconfig shows no new ifaces at all. Netstat shows no change, and no new
links.
Server log:
Mar 16 10:18:57 bell mpd: Multi-link PPP daemon for FreeBSD
Mar 16 10:18:57 bell mpd:
Mar 16 10:18:57 bell mpd: process 4493 started, version 5.5
(root@bell.herveybayaustralia.com.au 10:40 7-Mar-2011)
Mar 16 10:18:57 bell mpd: web: listening on 0.0.0.0 5006
Mar 16 10:18:57 bell mpd: EVENT: Registering event EVENT_READ MsgEvent()
at msg.c:72
Mar 16 10:18:57 bell mpd: EVENT: Registering event EVENT_READ MsgEvent()
done at msg.c:72
Mar 16 10:18:57 bell mpd: EVENT: Registering event EVENT_READ
L2tpServerEvent() at l2tp.c:1636
Mar 16 10:18:57 bell mpd: EVENT: Registering event EVENT_READ
L2tpServerEvent() done at l2tp.c:1636
Mar 16 10:18:57 bell mpd: L2TP: waiting for connection on 0.0.0.0 1701
Mar 16 10:18:57 bell mpd: EVENT: Processing event EVENT_TIMEOUT
ConfigRead() done
Mar 17 22:48:10 bell mpd: EVENT: Processing event EVENT_READ
L2tpServerEvent()
Mar 17 22:48:10 bell mpd: Incoming L2TP packet from 192.168.0.186 44424
Mar 17 22:48:10 bell mpd: L2TP: ppp_l2tp_ctrl_create invoked
Mar 17 22:48:10 bell mpd: L2TP: Control connection 0x286f3d08 0.0.0.0
1701 <-> 192.168.0.186 44424 accepted
Mar 17 22:48:10 bell mpd: EVENT: Processing event EVENT_READ
L2tpServerEvent() done
Mar 17 22:48:10 bell mpd: L2TP: RECV [MESSAGE_TYPE SCCRQ] [HOST_NAME
"<xxxxxxxx.domain.com>"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0x5fc2]
Mar 17 22:48:10 bell mpd: L2TP: rec'd SCCRQ in state idle
Mar 17 22:48:10 bell mpd: L2TP: connected to "<xxxxxxxx.domain.com>",
version=1.0
Mar 17 22:48:10 bell mpd: L2TP: XMIT [MESSAGE_TYPE SCCRP] [HOST_NAME
"bell.herveybayaustralia.com.au"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0x5801] [CHALLENGE 1b17d1b0a1de24a6117eb4212177e03f]
Mar 17 22:48:21 bell mpd: L2TP: RECV [MESSAGE_TYPE StopCCN]
[ASSIGNED_TUNNEL_ID 0x5fc2] [RESULT_CODE result=4 error=0 errmsg=""]
Mar 17 22:48:21 bell mpd: L2TP: rec'd StopCCN in state wait-ctl-conn
Mar 17 22:48:21 bell mpd: L2TP: Control connection 0x286f3d08
terminated: 0 ()
Mar 17 22:48:33 bell mpd: L2TP: Control connection 0x286f3d08 destroyed
Mar 17 22:49:04 bell mpd: EVENT: Processing event EVENT_READ
L2tpServerEvent()
Mar 17 22:49:04 bell mpd: Incoming L2TP packet from 192.168.0.186 60465
Mar 17 22:49:04 bell mpd: L2TP: ppp_l2tp_ctrl_create invoked
Mar 17 22:49:04 bell mpd: L2TP: Control connection 0x286f3d08 0.0.0.0
1701 <-> 192.168.0.186 60465 accepted
Mar 17 22:49:04 bell mpd: EVENT: Processing event EVENT_READ
L2tpServerEvent() done
Mar 17 22:49:04 bell mpd: L2TP: RECV [MESSAGE_TYPE SCCRQ] [HOST_NAME
"<xxxxxxxx.domain.com>"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0xaddc]
Mar 17 22:49:04 bell mpd: L2TP: rec'd SCCRQ in state idle
Mar 17 22:49:04 bell mpd: L2TP: connected to "<xxxxxxxx.domain.com>",
version=1.0
Mar 17 22:49:04 bell mpd: L2TP: XMIT [MESSAGE_TYPE SCCRP] [HOST_NAME
"bell.herveybayaustralia.com.au"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0xad98] [CHALLENGE 83d4b7a75fc9352b34d3e6ba52e7d569]
Mar 17 22:49:11 bell mpd: L2TP: RECV [MESSAGE_TYPE StopCCN]
[ASSIGNED_TUNNEL_ID 0xaddc] [RESULT_CODE result=4 error=0 errmsg=""]
Mar 17 22:49:11 bell mpd: L2TP: rec'd StopCCN in state wait-ctl-conn
Mar 17 22:49:11 bell mpd: L2TP: Control connection 0x286f3d08
terminated: 0 ()
Mar 17 22:49:11 bell mpd: EVENT: Processing event EVENT_READ
L2tpServerEvent()
Mar 17 22:49:11 bell mpd: Incoming L2TP packet from 192.168.0.186 53730
Mar 17 22:49:11 bell mpd: L2TP: ppp_l2tp_ctrl_create invoked
Mar 17 22:49:11 bell mpd: L2TP: Control connection 0x286f3a08 0.0.0.0
1701 <-> 192.168.0.186 53730 accepted
Mar 17 22:49:11 bell mpd: EVENT: Processing event EVENT_READ
L2tpServerEvent() done
Mar 17 22:49:11 bell mpd: L2TP: RECV [MESSAGE_TYPE SCCRQ] [HOST_NAME
"<xxxxxxxx.domain.com>"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0x651f]
Mar 17 22:49:11 bell mpd: L2TP: rec'd SCCRQ in state idle
Mar 17 22:49:11 bell mpd: L2TP: connected to "<xxxxxxxx.domain.com>",
version=1.0
Mar 17 22:49:11 bell mpd: L2TP: XMIT [MESSAGE_TYPE SCCRP] [HOST_NAME
"bell.herveybayaustralia.com.au"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0x6eb8] [CHALLENGE 850a97aab0a82865c949dcaa88742d5c]
Mar 17 22:49:14 bell mpd: L2TP: RECV [MESSAGE_TYPE StopCCN]
[ASSIGNED_TUNNEL_ID 0x651f] [RESULT_CODE result=4 error=0 errmsg=""]
Mar 17 22:49:14 bell mpd: L2TP: rec'd StopCCN in state wait-ctl-conn
Mar 17 22:49:14 bell mpd: L2TP: Control connection 0x286f3a08
terminated: 0 ()
Mar 17 22:49:14 bell mpd: EVENT: Processing event EVENT_READ
L2tpServerEvent()
Mar 17 22:49:14 bell mpd: Incoming L2TP packet from 192.168.0.186 26307
Mar 17 22:49:14 bell mpd: L2TP: ppp_l2tp_ctrl_create invoked
Mar 17 22:49:14 bell mpd: L2TP: Control connection 0x286f3708 0.0.0.0
1701 <-> 192.168.0.186 26307 accepted
Mar 17 22:49:14 bell mpd: EVENT: Processing event EVENT_READ
L2tpServerEvent() done
Mar 17 22:49:14 bell mpd: L2TP: RECV [MESSAGE_TYPE SCCRQ] [HOST_NAME
"<xxxxxxxx.domain.com>"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0xd587]
Mar 17 22:49:14 bell mpd: L2TP: rec'd SCCRQ in state idle
Mar 17 22:49:14 bell mpd: L2TP: connected to "<xxxxxxxx.domain.com>",
version=1.0
Mar 17 22:49:14 bell mpd: L2TP: XMIT [MESSAGE_TYPE SCCRP] [HOST_NAME
"bell.herveybayaustralia.com.au"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0x572b] [CHALLENGE d4bcf409e728dccde22eb4b8976c3da2]
Mar 17 22:49:17 bell mpd: L2TP: RECV [MESSAGE_TYPE StopCCN]
[ASSIGNED_TUNNEL_ID 0xd587] [RESULT_CODE result=4 error=0 errmsg=""]
Mar 17 22:49:17 bell mpd: L2TP: rec'd StopCCN in state wait-ctl-conn
Mar 17 22:49:17 bell mpd: L2TP: Control connection 0x286f3708
terminated: 0 ()
Mar 17 22:49:17 bell mpd: EVENT: Processing event EVENT_READ
L2tpServerEvent()
Mar 17 22:49:17 bell mpd: Incoming L2TP packet from 192.168.0.186 35205
Mar 17 22:49:17 bell mpd: L2TP: ppp_l2tp_ctrl_create invoked
Mar 17 22:49:17 bell mpd: L2TP: Control connection 0x286f3408 0.0.0.0
1701 <-> 192.168.0.186 35205 accepted
Mar 17 22:49:17 bell mpd: EVENT: Processing event EVENT_READ
L2tpServerEvent() done
Mar 17 22:49:17 bell mpd: L2TP: RECV [MESSAGE_TYPE SCCRQ] [HOST_NAME
"<xxxxxxxx.domain.com>"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0xdf8e]
Mar 17 22:49:17 bell mpd: L2TP: rec'd SCCRQ in state idle
Mar 17 22:49:17 bell mpd: L2TP: connected to "<xxxxxxxx.domain.com>",
version=1.0
Mar 17 22:49:17 bell mpd: L2TP: XMIT [MESSAGE_TYPE SCCRP] [HOST_NAME
"bell.herveybayaustralia.com.au"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0x0103] [CHALLENGE e752ac10b77559931fe2074c3e3221fa]
Mar 17 22:49:18 bell mpd: L2TP: RECV [MESSAGE_TYPE StopCCN]
[ASSIGNED_TUNNEL_ID 0xdf8e] [RESULT_CODE result=4 error=0 errmsg=""]
Mar 17 22:49:18 bell mpd: L2TP: rec'd StopCCN in state wait-ctl-conn
Mar 17 22:49:18 bell mpd: L2TP: Control connection 0x286f3408
terminated: 0 ()
Mar 17 22:49:18 bell mpd: EVENT: Processing event EVENT_READ
L2tpServerEvent()
Mar 17 22:49:18 bell mpd: Incoming L2TP packet from 192.168.0.186 16109
Mar 17 22:49:18 bell mpd: L2TP: ppp_l2tp_ctrl_create invoked
Mar 17 22:49:18 bell mpd: L2TP: Control connection 0x286f3108 0.0.0.0
1701 <-> 192.168.0.186 16109 accepted
Mar 17 22:49:18 bell mpd: EVENT: Processing event EVENT_READ
L2tpServerEvent() done
Mar 17 22:49:18 bell mpd: L2TP: RECV [MESSAGE_TYPE SCCRQ] [HOST_NAME
"<xxxxxxxx.domain.com>"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0x9a20]
Mar 17 22:49:18 bell mpd: L2TP: rec'd SCCRQ in state idle
Mar 17 22:49:18 bell mpd: L2TP: connected to "<xxxxxxxx.domain.com>",
version=1.0
Mar 17 22:49:18 bell mpd: L2TP: XMIT [MESSAGE_TYPE SCCRP] [HOST_NAME
"bell.herveybayaustralia.com.au"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0xcc26] [CHALLENGE 2ae14e07ae313562e9cdcf266fd20ec1]
Mar 17 22:49:19 bell mpd: L2TP: RECV [MESSAGE_TYPE StopCCN]
[ASSIGNED_TUNNEL_ID 0x9a20] [RESULT_CODE result=4 error=0 errmsg=""]
Mar 17 22:49:19 bell mpd: L2TP: rec'd StopCCN in state wait-ctl-conn
Mar 17 22:49:19 bell mpd: L2TP: Control connection 0x286f3108
terminated: 0 ()
Mar 17 22:49:21 bell mpd: EVENT: Processing event EVENT_READ
L2tpServerEvent()
Mar 17 22:49:21 bell mpd: Incoming L2TP packet from 192.168.0.186 16844
Mar 17 22:49:21 bell mpd: L2TP: ppp_l2tp_ctrl_create invoked
Mar 17 22:49:21 bell mpd: L2TP: Control connection 0x286f2e08 0.0.0.0
1701 <-> 192.168.0.186 16844 accepted
Mar 17 22:49:21 bell mpd: EVENT: Processing event EVENT_READ
L2tpServerEvent() done
Mar 17 22:49:21 bell mpd: L2TP: RECV [MESSAGE_TYPE SCCRQ] [HOST_NAME
"<xxxxxxxx.domain.com>"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0x4e71]
Mar 17 22:49:21 bell mpd: L2TP: rec'd SCCRQ in state idle
Mar 17 22:49:21 bell mpd: L2TP: connected to "<xxxxxxxx.domain.com>",
version=1.0
Mar 17 22:49:21 bell mpd: L2TP: XMIT [MESSAGE_TYPE SCCRP] [HOST_NAME
"bell.herveybayaustralia.com.au"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0x007e] [CHALLENGE 1e79f4770c13591460984681926dab74]
Mar 17 22:49:22 bell mpd: L2TP: Control connection 0x286f3d08 destroyed
Mar 17 22:49:22 bell mpd: L2TP: RECV [MESSAGE_TYPE StopCCN]
[ASSIGNED_TUNNEL_ID 0x4e71] [RESULT_CODE result=4 error=0 errmsg=""]
Mar 17 22:49:22 bell mpd: L2TP: rec'd StopCCN in state wait-ctl-conn
Mar 17 22:49:22 bell mpd: L2TP: Control connection 0x286f2e08
terminated: 0 ()
And it appears to continue.
Client log:
Mar 18 00:03:11 <client> mpd: [L1] Link: reconnection attempt 220 in 3
seconds
Mar 18 00:04:06 <client> mpd: L2TP: Control connection 0x801e93e10 destroyed
Mar 18 00:04:06 <client> mpd: [L1] Link: reconnection attempt 220
Mar 18 00:04:06 <client> mpd: L2TP: Control connection 0x801e93b10 destroyed
Mar 18 00:04:06 <client> mpd: L2TP: Initiating control connection
0x801e93b10 0.0.0.0 0 <-> 192.168.0.40 1701
Mar 18 00:04:06 <client> mpd: L2TP: Control connection 0x801e93b10
terminated: 0 ()
Mar 18 00:04:06 <client> mpd: [L1] Link: DOWN event
Mar 18 00:04:06 <client> mpd: [L1] LCP: Down event
Mar 18 00:04:06 <client> mpd: [L1] Link: reconnection attempt 221 in 1
seconds
Mar 18 00:04:16 <client> mpd: [L1] Link: reconnection attempt 221
Mar 18 00:04:17 <client> mpd: caught fatal signal term
Mar 18 00:04:17 <client> mpd: [B1] IFACE: Close event
Mar 18 00:04:17 <client> mpd: [B1] IPCP: Close event
Mar 18 00:04:17 <client> mpd: L2TP: Initiating control connection
0x801e93e10 0.0.0.0 0 <-> 192.168.0.40 1701
Mar 18 00:04:17 <client> mpd: L2TP: Control connection 0x801e93e10
terminated: 0 ()
Mar 18 00:04:17 <client> mpd: [L1] Link: DOWN event
Mar 18 00:04:17 <client> mpd: [L1] Link: giving up after 221
reconnection attempts
Mar 18 00:04:17 <client> mpd: [L1] LCP: Close event
Mar 18 00:04:17 <client> mpd: [L1] LCP: state change Starting --> Initial
Mar 18 00:04:17 <client> mpd: [L1] LCP: LayerFinish
Mar 18 00:04:17 <client> mpd: [L1] LCP: Down event
Mar 18 00:04:32 <client> mpd: L2TP: Control connection 0x801e93e10 destroyed
Mar 18 00:04:32 <client> mpd: [B1] Bundle: Shutdown
Mar 18 00:04:32 <client> mpd: [L1] Link: Shutdown
Mar 18 00:04:32 <client> mpd: process 20448 terminated
I added the line "set l2tp secret <secret>" and the client log:
Mar 18 16:26:22 <client> mpd: Multi-link PPP daemon for FreeBSD
Mar 18 16:26:22 <client> mpd:
Mar 18 16:26:22 <client> mpd: process 23373 started, version 5.5
(root@<xxxxxxxx.domain.com> 20:28 17-Mar-2011)
Mar 18 16:26:22 <client> mpd: web: listening on 0.0.0.0 5006
Mar 18 16:26:22 <client> mpd: [B1] Bundle: Interface ng0 created
Mar 18 16:26:22 <client> mpd: [L1] Link: OPEN event
Mar 18 16:26:22 <client> mpd: [L1] LCP: Open event
Mar 18 16:26:22 <client> mpd: [L1] LCP: state change Initial --> Starting
Mar 18 16:26:22 <client> mpd: [L1] LCP: LayerStart
Mar 18 16:26:22 <client> mpd: L2TP: Initiating control connection
0x801e94710 0.0.0.0 0 <-> 192.168.0.40 1701
Mar 18 16:26:22 <client> mpd: L2TP: Control connection 0x801e94710
192.168.0.186 43291 <-> 192.168.0.40 1701 connected
Mar 18 16:26:22 <client> mpd: [L1] L2TP: Incoming call #8630000 via
control connection 0x801e94710 initiated
Mar 18 16:26:57 <client> mpd: [L1] L2TP: Call #8630000 connected
Mar 18 16:26:57 <client> mpd: [L1] Link: UP event
Mar 18 16:26:57 <client> mpd: [L1] LCP: Up event
Mar 18 16:26:57 <client> mpd: [L1] LCP: state change Starting --> Req-Sent
Mar 18 16:26:57 <client> mpd: [L1] LCP: SendConfigReq #1
Mar 18 16:26:57 <client> mpd: [L1] ACFCOMP
Mar 18 16:26:57 <client> mpd: [L1] PROTOCOMP
Mar 18 16:26:57 <client> mpd: [L1] MRU 1500
Mar 18 16:26:57 <client> mpd: [L1] MAGICNUM 1769d002
Mar 18 16:26:57 <client> mpd: [L1] LCP: rec'd Configure Request #1
(Req-Sent)
Mar 18 16:26:57 <client> mpd: [L1] ACFCOMP
Mar 18 16:26:57 <client> mpd: [L1] PROTOCOMP
Mar 18 16:26:57 <client> mpd: [L1] MRU 1500
Mar 18 16:26:57 <client> mpd: [L1] MAGICNUM bdf70721
Mar 18 16:26:57 <client> mpd: [L1] AUTHPROTO CHAP MSOFTv2
Mar 18 16:26:57 <client> mpd: [L1] MP MRRU 2048
Mar 18 16:26:57 <client> mpd: [L1] MP SHORTSEQ
Mar 18 16:26:57 <client> mpd: [L1] ENDPOINTDISC [802.1] 00 1d 7d 79 9e 6e
Mar 18 16:26:57 <client> mpd: [L1] LCP: SendConfigRej #1
Mar 18 16:26:57 <client> mpd: [L1] MP MRRU 2048
Mar 18 16:26:57 <client> mpd: [L1] MP SHORTSEQ
Mar 18 16:26:57 <client> mpd: [L1] LCP: rec'd Configure Request #2
(Req-Sent)
Mar 18 16:26:57 <client> mpd: [L1] ACFCOMP
Mar 18 16:26:57 <client> mpd: [L1] PROTOCOMP
Mar 18 16:26:57 <client> mpd: [L1] MRU 1500
Mar 18 16:26:57 <client> mpd: [L1] MAGICNUM bdf70721
Mar 18 16:26:57 <client> mpd: [L1] AUTHPROTO CHAP MSOFTv2
Mar 18 16:26:57 <client> mpd: [L1] LCP: SendConfigAck #2
Mar 18 16:26:57 <client> mpd: [L1] ACFCOMP
Mar 18 16:26:57 <client> mpd: [L1] PROTOCOMP
Mar 18 16:26:57 <client> mpd: [L1] MRU 1500
Mar 18 16:26:57 <client> mpd: [L1] MAGICNUM bdf70721
Mar 18 16:26:57 <client> mpd: [L1] AUTHPROTO CHAP MSOFTv2
Mar 18 16:26:57 <client> mpd: [L1] LCP: state change Req-Sent --> Ack-Sent
Mar 18 16:26:59 <client> mpd: [L1] LCP: rec'd Configure Request #3
(Ack-Sent)
Mar 18 16:26:59 <client> mpd: [L1] ACFCOMP
Mar 18 16:26:59 <client> mpd: [L1] PROTOCOMP
Mar 18 16:26:59 <client> mpd: [L1] MRU 1500
Mar 18 16:26:59 <client> mpd: [L1] MAGICNUM bdf70721
Mar 18 16:26:59 <client> mpd: [L1] AUTHPROTO CHAP MSOFTv2
Mar 18 16:26:59 <client> mpd: [L1] LCP: SendConfigAck #3
Mar 18 16:26:59 <client> mpd: [L1] ACFCOMP
Mar 18 16:26:59 <client> mpd: [L1] PROTOCOMP
Mar 18 16:26:59 <client> mpd: [L1] MRU 1500
Mar 18 16:26:59 <client> mpd: [L1] MAGICNUM bdf70721
Mar 18 16:26:59 <client> mpd: [L1] AUTHPROTO CHAP MSOFTv2
Mar 18 16:26:59 <client> mpd: [L1] LCP: SendConfigReq #2
Mar 18 16:26:59 <client> mpd: [L1] ACFCOMP
Mar 18 16:26:59 <client> mpd: [L1] PROTOCOMP
Mar 18 16:26:59 <client> mpd: [L1] MRU 1500
Mar 18 16:26:59 <client> mpd: [L1] MAGICNUM 1769d002
Mar 18 16:26:59 <client> mpd: [L1] LCP: rec'd Configure Ack #2 (Ack-Sent)
Mar 18 16:26:59 <client> mpd: [L1] ACFCOMP
Mar 18 16:26:59 <client> mpd: [L1] PROTOCOMP
Mar 18 16:26:59 <client> mpd: [L1] MRU 1500
Mar 18 16:26:59 <client> mpd: [L1] MAGICNUM 1769d002
Mar 18 16:26:59 <client> mpd: [L1] LCP: state change Ack-Sent --> Opened
Mar 18 16:26:59 <client> mpd: [L1] LCP: auth: peer wants CHAP, I want
nothing
Mar 18 16:26:59 <client> mpd: [L1] LCP: LayerUp
Mar 18 16:26:59 <client> mpd: [L1] CHAP: rec'd CHALLENGE #1 len: 21
Mar 18 16:26:59 <client> mpd: [L1] Name: ""
Mar 18 16:26:59 <client> mpd: [L1] CHAP: Using authname "<username>"
Mar 18 16:26:59 <client> mpd: [L1] CHAP: sending RESPONSE #1 len: 63
Mar 18 16:26:59 <client> mpd: [L1] CHAP: rec'd SUCCESS #1 len: 46
Mar 18 16:26:59 <client> mpd: [L1] MESG:
S=D189BC01B0EDCCD8C463FA858FE0F3AEFF2F95E4
Mar 18 16:26:59 <client> mpd: [L1] LCP: authorization successful
Mar 18 16:26:59 <client> mpd: [L1] Link: Matched action 'bundle "B1" ""'
Mar 18 16:26:59 <client> mpd: [L1] Link: Join bundle "B1"
Mar 18 16:26:59 <client> mpd: [B1] Bundle: Status update: up 1 link,
total bandwidth 64000 bps
Mar 18 16:26:59 <client> mpd: [B1] IPCP: Open event
Mar 18 16:26:59 <client> mpd: [B1] IPCP: state change Initial --> Starting
Mar 18 16:26:59 <client> mpd: [B1] IPCP: LayerStart
Mar 18 16:26:59 <client> mpd: [B1] IPCP: Up event
Mar 18 16:26:59 <client> mpd: [B1] IPCP: state change Starting --> Req-Sent
Mar 18 16:26:59 <client> mpd: [B1] IPCP: SendConfigReq #1
Mar 18 16:26:59 <client> mpd: [B1] IPADDR 0.0.0.0
Mar 18 16:26:59 <client> mpd: [B1] COMPPROTO VJCOMP, 16 comp.
channels, no comp-cid
Mar 18 16:26:59 <client> mpd: [B1] IPCP: rec'd Configure Request #1
(Req-Sent)
Mar 18 16:26:59 <client> mpd: [B1] IPADDR 192.168.0.40
Mar 18 16:26:59 <client> mpd: [B1] 192.168.0.40 is OK
Mar 18 16:26:59 <client> mpd: [B1] COMPPROTO VJCOMP, 16 comp.
channels, no comp-cid
Mar 18 16:26:59 <client> mpd: [B1] IPCP: SendConfigAck #1
Mar 18 16:26:59 <client> mpd: [B1] IPADDR 192.168.0.40
Mar 18 16:26:59 <client> mpd: [B1] COMPPROTO VJCOMP, 16 comp.
channels, no comp-cid
Mar 18 16:26:59 <client> mpd: [B1] IPCP: state change Req-Sent --> Ack-Sent
Mar 18 16:26:59 <client> mpd: [L1] rec'd unexpected protocol CCP, rejecting
Mar 18 16:26:59 <client> mpd: [B1] IPCP: rec'd Configure Nak #1 (Ack-Sent)
Mar 18 16:26:59 <client> mpd: [B1] IPADDR 192.168.0.42
Mar 18 16:26:59 <client> mpd: [B1] 192.168.0.42 is OK
Mar 18 16:26:59 <client> mpd: [B1] IPCP: SendConfigReq #2
Mar 18 16:26:59 <client> mpd: [B1] IPADDR 192.168.0.42
Mar 18 16:26:59 <client> mpd: [B1] COMPPROTO VJCOMP, 16 comp.
channels, no comp-cid
Mar 18 16:26:59 <client> mpd: [B1] IPCP: rec'd Configure Ack #2 (Ack-Sent)
Mar 18 16:26:59 <client> mpd: [B1] IPADDR 192.168.0.42
Mar 18 16:26:59 <client> mpd: [B1] COMPPROTO VJCOMP, 16 comp.
channels, no comp-cid
Mar 18 16:26:59 <client> mpd: [B1] IPCP: state change Ack-Sent --> Opened
Mar 18 16:26:59 <client> mpd: [B1] IPCP: LayerUp
Mar 18 16:26:59 <client> mpd: [B1] 192.168.0.42 -> 192.168.0.40
Mar 18 16:26:59 <client> mpd: [B1] IFACE: Add route 0.0.0.0/0
192.168.0.40 failed: File exists
Mar 18 16:26:59 <client> mpd: [B1] IFACE: Up event
Mar 18 16:27:10 <client> kernel: Loop detected on ng0
Mar 18 16:27:15 <client> kernel: Loop detected on ng0
Mar 18 16:27:16 <client> mpd: caught fatal signal term
Mar 18 16:27:16 <client> mpd: [B1] IFACE: Close event
Mar 18 16:27:16 <client> mpd: [B1] IPCP: Close event
Mar 18 16:27:16 <client> mpd: [B1] IPCP: state change Opened --> Closing
Mar 18 16:27:16 <client> mpd: [B1] IPCP: SendTerminateReq #3
Mar 18 16:27:16 <client> mpd: [B1] IPCP: LayerDown
Mar 18 16:27:16 <client> kernel: Loop detected on ng0
Mar 18 16:27:16 <client> mpd: [B1] IFACE: Down event
Mar 18 16:27:19 <client> mpd: [B1] Bundle: Shutdown
Mar 18 16:27:19 <client> mpd: [L1] Link: Shutdown
Mar 18 16:27:19 <client> mpd: process 23373 terminated
Server log:
Mar 18 16:24:21 bell mpd: Multi-link PPP daemon for FreeBSD
Mar 18 16:24:21 bell mpd:
Mar 18 16:24:21 bell mpd: process 18243 started, version 5.5
(root@bell.herveybayaustralia.com.au 10:40 7-Mar-2011)
Mar 18 16:24:21 bell mpd: web: listening on 0.0.0.0 5006
Mar 18 16:24:21 bell mpd: EVENT: Registering event EVENT_READ MsgEvent()
at msg.c:72
Mar 18 16:24:21 bell mpd: EVENT: Registering event EVENT_READ MsgEvent()
done at msg.c:72
Mar 18 16:24:21 bell mpd: EVENT: Registering event EVENT_READ
L2tpServerEvent() at l2tp.c:1636
Mar 18 16:24:21 bell mpd: EVENT: Registering event EVENT_READ
L2tpServerEvent() done at l2tp.c:1636
Mar 18 16:24:21 bell mpd: L2TP: waiting for connection on 0.0.0.0 1701
Mar 18 16:24:21 bell mpd: EVENT: Processing event EVENT_TIMEOUT
ConfigRead() done
Mar 18 16:24:26 bell mpd: EVENT: Processing event EVENT_READ
L2tpServerEvent()
Mar 18 16:24:26 bell mpd: Incoming L2TP packet from 192.168.0.186 43291
Mar 18 16:24:26 bell mpd: L2TP: ppp_l2tp_ctrl_create invoked
Mar 18 16:24:26 bell mpd: L2TP: Control connection 0x286f3d08 0.0.0.0
1701 <-> 192.168.0.186 43291 accepted
Mar 18 16:24:26 bell mpd: EVENT: Processing event EVENT_READ
L2tpServerEvent() done
Mar 18 16:24:26 bell mpd: L2TP: RECV [MESSAGE_TYPE SCCRQ] [HOST_NAME
"<xxxxxxxx.domain.com>"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0x149f] [CHALLENGE bf74c86bdf140609a3168c874e3754c3]
Mar 18 16:24:26 bell mpd: L2TP: rec'd SCCRQ in state idle
Mar 18 16:24:26 bell mpd: L2TP: connected to "<xxxxxxxx.domain.com>",
version=1.0
Mar 18 16:24:26 bell mpd: L2TP: XMIT [MESSAGE_TYPE SCCRP] [HOST_NAME
"bell.herveybayaustralia.com.au"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0x8816] [CHALLENGE d24c6f0c756870bba6fd30ac8bd51bc7]
[CHALLENGE_RESPONSE e8eefb6ae3db3ad3b2d1ad43d1022ac1]
Mar 18 16:25:01 bell mpd: L2TP: RECV [MESSAGE_TYPE SCCCN] [HOST_NAME
"<xxxxxxxx.domain.com>"] [VENDOR_NAME "FreeBSD MPD"]
[BEARER_CAPABILITIES digital=1 analog=1] [RECEIVE_WINDOW_SIZE 8]
[PROTOCOL_VERSION 1.0] [FRAMING_CAPABILITIES sync=1 async=1]
[ASSIGNED_TUNNEL_ID 0x149f] [CHALLENGE bf74c86bdf140609a3168c874e3754c3]
[CHALLENGE_RESPONSE b448a55b0f44a75aa3e9b118d442df00]
Mar 18 16:25:01 bell mpd: L2TP: rec'd SCCCN in state wait-ctl-conn
Mar 18 16:25:01 bell mpd: L2TP: Control connection 0x286f3d08 0.0.0.0
1701 <-> 192.168.0.186 43291 connected
Mar 18 16:25:01 bell mpd: L2TP: RECV [MESSAGE_TYPE ICRQ]
[ASSIGNED_SESSION_ID 0xa9dc] [CALL_SERIAL_NUMBER 8630000]
Mar 18 16:25:01 bell mpd: L2TP: rec'd ICRQ in state established
Mar 18 16:25:01 bell mpd: L2TP: created new session #8630000 id 0xef17
orig=remote side=LNS state=wait-connect
Mar 18 16:25:01 bell mpd: L2TP: Incoming call #8630000 via connection
0x286f3d08 received
Mar 18 16:25:01 bell mpd: [L1-1] L2TP: Incoming call #8630000 via
control connection 0x286f3d08 accepted
Mar 18 16:25:01 bell mpd: EVENT: Message 1 to LinkMsg() sent
Mar 18 16:25:01 bell mpd: L2TP: XMIT(0xa9dc) [MESSAGE_TYPE ICRP]
[ASSIGNED_SESSION_ID 0xef17]
Mar 18 16:25:01 bell mpd: EVENT: Processing event EVENT_READ MsgEvent()
Mar 18 16:25:01 bell mpd: EVENT: Message 1 to LinkMsg() received
Mar 18 16:25:01 bell mpd: [L1-1] Link: OPEN event
Mar 18 16:25:01 bell mpd: [L1-1] LCP: Open event
Mar 18 16:25:01 bell mpd: [L1-1] LCP: state change Initial --> Starting
Mar 18 16:25:01 bell mpd: EVENT: Stopping timer "(null)" (null)() at
fsm.c:190
Mar 18 16:25:01 bell mpd: [L1-1] LCP: LayerStart
Mar 18 16:25:01 bell mpd: EVENT: Message 1 to PhysMsg() sent
Mar 18 16:25:01 bell mpd: EVENT: Message 1 to LinkMsg() processed
Mar 18 16:25:01 bell mpd: EVENT: Message 1 to PhysMsg() received
Mar 18 16:25:01 bell mpd: [L1-1] device: OPEN event
Mar 18 16:25:01 bell mpd: [L1-1] L2tpOpen() on incoming call
Mar 18 16:25:01 bell mpd: EVENT: Message 1 to PhysMsg() processed
Mar 18 16:25:01 bell mpd: EVENT: Processing event EVENT_READ MsgEvent() done
Mar 18 16:25:01 bell mpd: EVENT: Processing event EVENT_READ MsgEvent()
Mar 18 16:25:01 bell mpd: EVENT: Processing event EVENT_READ MsgEvent() done
Mar 18 16:25:01 bell mpd: L2TP: RECV(0x17ef) [MESSAGE_TYPE ICCN]
[TX_CONNECT_SPEED 10000000] [FRAMING_TYPE sync=1 async=0]
Mar 18 16:25:01 bell mpd: L2TP: rec'd ICCN in state wait-connect
Mar 18 16:25:01 bell mpd: [L1-1] L2TP: Call #8630000 connected
Mar 18 16:25:01 bell mpd: [L1-1] device: UP event
Mar 18 16:25:01 bell mpd: [L1-1] Link: UP event
Mar 18 16:25:01 bell mpd: [L1-1] Link: origination is remote
Mar 18 16:25:01 bell mpd: [L1-1] LCP: Up event
Mar 18 16:25:01 bell mpd: [L1-1] LCP: state change Starting --> Req-Sent
Mar 18 16:25:01 bell mpd: [L1-1] LCP: phase shift DEAD --> ESTABLISH
Mar 18 16:25:01 bell mpd: EVENT: Stopping timer "(null)" (null)() at
fsm.c:531
Mar 18 16:25:01 bell mpd: [L1-1] LCP: SendConfigReq #1
Mar 18 16:25:01 bell mpd: [L1-1] ACFCOMP
Mar 18 16:25:01 bell mpd: [L1-1] PROTOCOMP
Mar 18 16:25:01 bell mpd: [L1-1] MRU 1500
Mar 18 16:25:01 bell mpd: [L1-1] MAGICNUM bdf70721
Mar 18 16:25:01 bell mpd: [L1-1] AUTHPROTO CHAP MSOFTv2
Mar 18 16:25:01 bell mpd: [L1-1] MP MRRU 2048
Mar 18 16:25:01 bell mpd: [L1-1] MP SHORTSEQ
Mar 18 16:25:01 bell mpd: [L1-1] ENDPOINTDISC [802.1] 00 1d 7d 79 9e 6e
Mar 18 16:25:01 bell mpd: [L1-1] xmit frame to link proto=0xc021
Mar 18 16:25:01 bell mpd: ff 03 c0 21 01 01 00 26 08 02 07 02 01 04
05 dc ...!...&........
Mar 18 16:25:01 bell mpd: 05 06 bd f7 07 21 03 05 c2 23 81 11 04 08
00 12 .....!...#......
Mar 18 16:25:01 bell mpd: 02 13 09 03 00 1d 7d 79 9e
6e ......}y.n
Mar 18 16:25:01 bell mpd: EVENT: Starting timer "LCP" FsmTimeout() for
2000 ms at fsm.c:426
Mar 18 16:25:01 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() at timer.c:50
Mar 18 16:25:01 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() done at timer.c:50
Mar 18 16:25:01 bell mpd: EVENT: Processing event EVENT_READ
LinkNgDataEvent()
Mar 18 16:25:01 bell mpd: [L1-1] rec'd 14 bytes frame from link proto=0xc021
Mar 18 16:25:01 bell mpd: ff 03 c0 21 04 01 00 0a 11 04 08 00 12
02 ...!..........
Mar 18 16:25:01 bell mpd: [L1-1] LCP: rec'd Configure Reject #1 (Req-Sent)
Mar 18 16:25:01 bell mpd: [L1-1] MP MRRU 2048
Mar 18 16:25:01 bell mpd: [L1-1] MP SHORTSEQ
Mar 18 16:25:01 bell mpd: EVENT: Stopping timer "LCP" FsmTimeout() at
fsm.c:531
Mar 18 16:25:01 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() at timer.c:83
Mar 18 16:25:01 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() done at timer.c:83
Mar 18 16:25:01 bell mpd: [L1-1] LCP: SendConfigReq #2
Mar 18 16:25:01 bell mpd: [L1-1] ACFCOMP
Mar 18 16:25:01 bell mpd: [L1-1] PROTOCOMP
Mar 18 16:25:01 bell mpd: [L1-1] MRU 1500
Mar 18 16:25:01 bell mpd: [L1-1] MAGICNUM bdf70721
Mar 18 16:25:01 bell mpd: [L1-1] AUTHPROTO CHAP MSOFTv2
Mar 18 16:25:01 bell mpd: [L1-1] xmit frame to link proto=0xc021
Mar 18 16:25:01 bell mpd: ff 03 c0 21 01 02 00 17 08 02 07 02 01 04
05 dc ...!............
Mar 18 16:25:01 bell mpd: 05 06 bd f7 07 21 03 05 c2 23
81 .....!...#.
Mar 18 16:25:01 bell mpd: EVENT: Starting timer "LCP" FsmTimeout() for
2000 ms at fsm.c:426
Mar 18 16:25:01 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() at timer.c:50
Mar 18 16:25:01 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() done at timer.c:50
Mar 18 16:25:01 bell mpd: EVENT: Processing event EVENT_READ
LinkNgDataEvent() done
Mar 18 16:25:01 bell mpd: EVENT: Processing event EVENT_READ
LinkNgDataEvent()
Mar 18 16:25:01 bell mpd: [L1-1] rec'd 27 bytes frame from link proto=0xc021
Mar 18 16:25:01 bell mpd: ff 03 c0 21 02 02 00 17 08 02 07 02 01 04
05 dc ...!............
Mar 18 16:25:01 bell mpd: 05 06 bd f7 07 21 03 05 c2 23
81 .....!...#.
Mar 18 16:25:01 bell mpd: [L1-1] LCP: rec'd Configure Ack #2 (Req-Sent)
Mar 18 16:25:01 bell mpd: [L1-1] ACFCOMP
Mar 18 16:25:01 bell mpd: [L1-1] PROTOCOMP
Mar 18 16:25:01 bell mpd: [L1-1] MRU 1500
Mar 18 16:25:01 bell mpd: [L1-1] MAGICNUM bdf70721
Mar 18 16:25:01 bell mpd: [L1-1] AUTHPROTO CHAP MSOFTv2
Mar 18 16:25:01 bell mpd: [L1-1] LCP: state change Req-Sent --> Ack-Rcvd
Mar 18 16:25:01 bell mpd: EVENT: Stopping timer "LCP" FsmTimeout() at
fsm.c:531
Mar 18 16:25:01 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() at timer.c:83
Mar 18 16:25:01 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() done at timer.c:83
Mar 18 16:25:01 bell mpd: EVENT: Starting timer "LCP" FsmTimeout() for
2000 ms at fsm.c:683
Mar 18 16:25:01 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() at timer.c:50
Mar 18 16:25:01 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() done at timer.c:50
Mar 18 16:25:01 bell mpd: EVENT: Processing event EVENT_READ
LinkNgDataEvent() done
Mar 18 16:25:03 bell mpd: EVENT: Processing event EVENT_TIMEOUT
TimerExpires()
Mar 18 16:25:03 bell mpd: EVENT: Processing timer "LCP" FsmTimeout()
Mar 18 16:25:03 bell mpd: [L1-1] LCP: state change Ack-Rcvd --> Req-Sent
Mar 18 16:25:03 bell mpd: [L1-1] LCP: SendConfigReq #3
Mar 18 16:25:03 bell mpd: [L1-1] ACFCOMP
Mar 18 16:25:03 bell mpd: [L1-1] PROTOCOMP
Mar 18 16:25:03 bell mpd: [L1-1] MRU 1500
Mar 18 16:25:03 bell mpd: [L1-1] MAGICNUM bdf70721
Mar 18 16:25:03 bell mpd: [L1-1] AUTHPROTO CHAP MSOFTv2
Mar 18 16:25:03 bell mpd: [L1-1] xmit frame to link proto=0xc021
Mar 18 16:25:03 bell mpd: ff 03 c0 21 01 03 00 17 08 02 07 02 01 04
05 dc ...!............
Mar 18 16:25:03 bell mpd: 05 06 bd f7 07 21 03 05 c2 23
81 .....!...#.
Mar 18 16:25:03 bell mpd: EVENT: Starting timer "LCP" FsmTimeout() for
2000 ms at fsm.c:426
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() at timer.c:50
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() done at timer.c:50
Mar 18 16:25:03 bell mpd: EVENT: Processing timer "LCP" FsmTimeout() done
Mar 18 16:25:03 bell mpd: EVENT: Processing event EVENT_TIMEOUT
TimerExpires() done
Mar 18 16:25:03 bell mpd: EVENT: Processing event EVENT_READ
LinkNgDataEvent()
Mar 18 16:25:03 bell mpd: [L1-1] rec'd 27 bytes frame from link proto=0xc021
Mar 18 16:25:03 bell mpd: ff 03 c0 21 02 03 00 17 08 02 07 02 01 04
05 dc ...!............
Mar 18 16:25:03 bell mpd: 05 06 bd f7 07 21 03 05 c2 23
81 .....!...#.
Mar 18 16:25:03 bell mpd: [L1-1] LCP: rec'd Configure Ack #3 (Req-Sent)
Mar 18 16:25:03 bell mpd: [L1-1] ACFCOMP
Mar 18 16:25:03 bell mpd: [L1-1] PROTOCOMP
Mar 18 16:25:03 bell mpd: [L1-1] MRU 1500
Mar 18 16:25:03 bell mpd: [L1-1] MAGICNUM bdf70721
Mar 18 16:25:03 bell mpd: [L1-1] AUTHPROTO CHAP MSOFTv2
Mar 18 16:25:03 bell mpd: [L1-1] LCP: state change Req-Sent --> Ack-Rcvd
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "LCP" FsmTimeout() at
fsm.c:531
Mar 18 16:25:03 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() at timer.c:83
Mar 18 16:25:03 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() done at timer.c:83
Mar 18 16:25:03 bell mpd: EVENT: Starting timer "LCP" FsmTimeout() for
2000 ms at fsm.c:683
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() at timer.c:50
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() done at timer.c:50
Mar 18 16:25:03 bell mpd: [L1-1] rec'd 22 bytes frame from link proto=0xc021
Mar 18 16:25:03 bell mpd: ff 03 c0 21 01 02 00 12 08 02 07 02 01 04
05 dc ...!............
Mar 18 16:25:03 bell mpd: 05 06 17 69 d0
02 ...i..
Mar 18 16:25:03 bell mpd: [L1-1] LCP: rec'd Configure Request #2 (Ack-Rcvd)
Mar 18 16:25:03 bell mpd: [L1-1] ACFCOMP
Mar 18 16:25:03 bell mpd: [L1-1] PROTOCOMP
Mar 18 16:25:03 bell mpd: [L1-1] MRU 1500
Mar 18 16:25:03 bell mpd: [L1-1] MAGICNUM 1769d002
Mar 18 16:25:03 bell mpd: [L1-1] LCP: SendConfigAck #2
Mar 18 16:25:03 bell mpd: [L1-1] ACFCOMP
Mar 18 16:25:03 bell mpd: [L1-1] PROTOCOMP
Mar 18 16:25:03 bell mpd: [L1-1] MRU 1500
Mar 18 16:25:03 bell mpd: [L1-1] MAGICNUM 1769d002
Mar 18 16:25:03 bell mpd: [L1-1] xmit frame to link proto=0xc021
Mar 18 16:25:03 bell mpd: ff 03 c0 21 02 02 00 12 08 02 07 02 01 04
05 dc ...!............
Mar 18 16:25:03 bell mpd: 05 06 17 69 d0
02 ...i..
Mar 18 16:25:03 bell mpd: [L1-1] LCP: state change Ack-Rcvd --> Opened
Mar 18 16:25:03 bell mpd: [L1-1] LCP: phase shift ESTABLISH --> AUTHENTICATE
Mar 18 16:25:03 bell mpd: [L1-1] LCP: auth: peer wants nothing, I want CHAP
Mar 18 16:25:03 bell mpd: EVENT: Starting timer "AuthTimer"
AuthTimeout() for 40000 ms at auth.c:387
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() at timer.c:50
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() done at timer.c:50
Mar 18 16:25:03 bell mpd: EVENT: Starting timer "ChalTimer"
ChapChalTimeout() for 2000 ms at chap.c:75
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() at timer.c:50
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() done at timer.c:50
Mar 18 16:25:03 bell mpd: [L1-1] CHAP: sending CHALLENGE #1 len: 21
Mar 18 16:25:03 bell mpd: [L1-1] xmit frame to link proto=0xc223
Mar 18 16:25:03 bell mpd: ff 03 c2 23 01 01 00 15 10 bb 1e 68 08 ce
bc 0f ...#.......h....
Mar 18 16:25:03 bell mpd: bb 73 0d c6 78 25 50 92
3b .s..x%P.;
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "LCP" FsmTimeout() at
fsm.c:190
Mar 18 16:25:03 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() at timer.c:83
Mar 18 16:25:03 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() done at timer.c:83
Mar 18 16:25:03 bell mpd: EVENT: Starting recurring timer "FsmKeepAlive"
FsmEchoTimeout() for 5000 ms at fsm.c:200
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() at timer.c:69
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() done at timer.c:69
Mar 18 16:25:03 bell mpd: [L1-1] LCP: LayerUp
Mar 18 16:25:03 bell mpd: EVENT: Processing event EVENT_READ
LinkNgDataEvent() done
Mar 18 16:25:03 bell mpd: EVENT: Processing event EVENT_READ
LinkNgDataEvent()
Mar 18 16:25:03 bell mpd: [L1-1] rec'd 67 bytes frame from link proto=0xc223
Mar 18 16:25:03 bell mpd: ff 03 c2 23 02 01 00 3f 31 7b 1e 68 ed 57
99 8e ...#...?1{.h.W..
Mar 18 16:25:03 bell mpd: 95 4a e7 6c 23 45 38 f1 b9 00 00 00 00 00
00 00 .J.l#E8.........
Mar 18 16:25:03 bell mpd: 00 37 1e db 46 3a 5c 61 b4 62 c9 bd ec 83
b7 c9 .7..F:\a.b......
Mar 18 16:25:03 bell mpd: 84 66 9b 58 78 59 47 c4 e5 01 6e 72 73 6b
69 6e .f.XxYG...nrskin
Mar 18 16:25:03 bell mpd: 6e 65
72 ner
Mar 18 16:25:03 bell mpd: [L1-1] CHAP: rec'd RESPONSE #1 len: 63
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "ChalTimer"
ChapChalTimeout() at chap.c:402
Mar 18 16:25:03 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() at timer.c:83
Mar 18 16:25:03 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() done at timer.c:83
Mar 18 16:25:03 bell mpd: [L1-1] Name: "<username>"
Mar 18 16:25:03 bell mpd: EVENT: Processing event EVENT_READ
LinkNgDataEvent() done
Mar 18 16:25:03 bell mpd: [L1-1] AUTH: Thread started
Mar 18 16:25:03 bell mpd: [L1-1] AUTH: Trying INTERNAL
Mar 18 16:25:03 bell mpd: [L1-1] AUTH: INTERNAL returned: undefined
Mar 18 16:25:03 bell mpd: [L1-1] AUTH: Thread finished normally
Mar 18 16:25:03 bell mpd: [L1-1] CHAP: Auth return status: undefined
Mar 18 16:25:03 bell mpd: [L1-1] CHAP: Response is valid
Mar 18 16:25:03 bell mpd: [L1-1] CHAP: Reply message:
S=D189BC01B0EDCCD8C463FA858FE0F3AEFF2F95E4
Mar 18 16:25:03 bell mpd: [L1-1] CHAP: sending SUCCESS #1 len: 46
Mar 18 16:25:03 bell mpd: [L1-1] xmit frame to link proto=0xc223
Mar 18 16:25:03 bell mpd: ff 03 c2 23 03 01 00 2e 53 3d 44 31 38 39
42 43 ...#....S=D189BC
Mar 18 16:25:03 bell mpd: 30 31 42 30 45 44 43 43 44 38 43 34 36 33
46 41 01B0EDCCD8C463FA
Mar 18 16:25:03 bell mpd: 38 35 38 46 45 30 46 33 41 45 46 46 32 46
39 35 858FE0F3AEFF2F95
Mar 18 16:25:03 bell mpd: 45
34 E4
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "AuthTimer"
AuthTimeout() at auth.c:682
Mar 18 16:25:03 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() at timer.c:83
Mar 18 16:25:03 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() done at timer.c:83
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "(null)" (null)() at
pap.c:64
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "ChalTimer"
ChapChalTimeout() at chap.c:93
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "(null)" (null)() at
chap.c:94
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "(null)" (null)() at
eap.c:146
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "(null)" (null)() at
eap.c:147
Mar 18 16:25:03 bell mpd: [L1-1] LCP: authorization successful
Mar 18 16:25:03 bell mpd: [L1-1] LCP: phase shift AUTHENTICATE --> NETWORK
Mar 18 16:25:03 bell mpd: [L1-1] Link: Matched action 'bundle "B1" ""'
Mar 18 16:25:03 bell mpd: [L1-1] Creating new bundle using template "B1".
Mar 18 16:25:03 bell mpd: [B1-1] Bundle: Interface ng0 created
Mar 18 16:25:03 bell mpd: [L1-1] Link: Join bundle "B1-1"
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "(null)" (null)() at
bund.c:310
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "(null)" (null)() at
bund.c:1479
Mar 18 16:25:03 bell mpd: [B1-1] IFACE: setting ng0 MTU to 1460 bytes
Mar 18 16:25:03 bell mpd: [B1-1] Bundle: Status update: up 1 link, total
bandwidth 64000 bps
Mar 18 16:25:03 bell mpd: [B1-1] IPCP: Open event
Mar 18 16:25:03 bell mpd: [B1-1] IPCP: state change Initial --> Starting
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "(null)" (null)() at
fsm.c:190
Mar 18 16:25:03 bell mpd: [B1-1] IPCP: LayerStart
Mar 18 16:25:03 bell mpd: [B1-1] CCP: Open event
Mar 18 16:25:03 bell mpd: [B1-1] CCP: state change Initial --> Starting
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "(null)" (null)() at
fsm.c:190
Mar 18 16:25:03 bell mpd: [B1-1] CCP: LayerStart
Mar 18 16:25:03 bell mpd: [B1-1] IPCP: Up event
Mar 18 16:25:03 bell mpd: [B1-1] IPCP: Got IP 192.168.0.42 from pool
"pool1" for peer
Mar 18 16:25:03 bell mpd: [B1-1] IPCP: state change Starting --> Req-Sent
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "(null)" (null)() at
fsm.c:531
Mar 18 16:25:03 bell mpd: [B1-1] IPCP: SendConfigReq #1
Mar 18 16:25:03 bell mpd: [B1-1] IPADDR 192.168.0.40
Mar 18 16:25:03 bell mpd: [B1-1] COMPPROTO VJCOMP, 16 comp. channels,
no comp-cid
Mar 18 16:25:03 bell mpd: [B1-1] xmit bypass frame link=-1 proto=0x8021
Mar 18 16:25:03 bell mpd: ff ff 80 21 01 01 00 10 03 06 c0 a8 00 28
02 06 ...!.........(..
Mar 18 16:25:03 bell mpd: 00 2d 0f
00 .-..
Mar 18 16:25:03 bell mpd: EVENT: Starting timer "IPCP" FsmTimeout() for
2000 ms at fsm.c:426
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() at timer.c:50
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() done at timer.c:50
Mar 18 16:25:03 bell mpd: [B1-1] CCP: Up event
Mar 18 16:25:03 bell mpd: [B1-1] CCP: state change Starting --> Req-Sent
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "(null)" (null)() at
fsm.c:531
Mar 18 16:25:03 bell mpd: [B1-1] CCP: SendConfigReq #1
Mar 18 16:25:03 bell mpd: [B1-1] xmit bypass frame link=-1 proto=0x80fd
Mar 18 16:25:03 bell mpd: ff ff 80 fd 01 01 00
04 ........
Mar 18 16:25:03 bell mpd: EVENT: Starting timer "CCP" FsmTimeout() for
2000 ms at fsm.c:426
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() at timer.c:50
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() done at timer.c:50
Mar 18 16:25:03 bell mpd: EVENT: Processing event EVENT_READ
LinkNgDataEvent()
Mar 18 16:25:03 bell mpd: [L1-1] rec'd 18 bytes frame from link proto=0x8021
Mar 18 16:25:03 bell mpd: 80 21 01 01 00 10 03 06 00 00 00 00 02 06
00 2d .!.............-
Mar 18 16:25:03 bell mpd: 0f
00 ..
Mar 18 16:25:03 bell mpd: [B1-1] IPCP: rec'd Configure Request #1 (Req-Sent)
Mar 18 16:25:03 bell mpd: [B1-1] IPADDR 0.0.0.0
Mar 18 16:25:03 bell mpd: [B1-1] NAKing with 192.168.0.42
Mar 18 16:25:03 bell mpd: [B1-1] COMPPROTO VJCOMP, 16 comp. channels,
no comp-cid
Mar 18 16:25:03 bell mpd: [B1-1] IPCP: SendConfigNak #1
Mar 18 16:25:03 bell mpd: [B1-1] IPADDR 192.168.0.42
Mar 18 16:25:03 bell mpd: [B1-1] xmit bypass frame link=-1 proto=0x8021
Mar 18 16:25:03 bell mpd: ff ff 80 21 03 01 00 0a 03 06 c0 a8 00
2a ...!.........*
Mar 18 16:25:03 bell mpd: [B1-1] rec'd 16 bytes bypass frame link=0
proto=0x8021
Mar 18 16:25:03 bell mpd: 02 01 00 10 03 06 c0 a8 00 28 02 06 00 2d
0f 00 .........(...-..
Mar 18 16:25:03 bell mpd: [B1-1] IPCP: rec'd Configure Ack #1 (Req-Sent)
Mar 18 16:25:03 bell mpd: [B1-1] IPADDR 192.168.0.40
Mar 18 16:25:03 bell mpd: [B1-1] COMPPROTO VJCOMP, 16 comp. channels,
no comp-cid
Mar 18 16:25:03 bell mpd: [B1-1] IPCP: state change Req-Sent --> Ack-Rcvd
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "IPCP" FsmTimeout() at
fsm.c:531
Mar 18 16:25:03 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() at timer.c:83
Mar 18 16:25:03 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() done at timer.c:83
Mar 18 16:25:03 bell mpd: EVENT: Starting timer "IPCP" FsmTimeout() for
2000 ms at fsm.c:683
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() at timer.c:50
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() done at timer.c:50
Mar 18 16:25:03 bell mpd: [B1-1] rec'd 10 bytes bypass frame link=0
proto=0xc021
Mar 18 16:25:03 bell mpd: 08 01 00 0a 80 fd 01 01 00
04 ..........
Mar 18 16:25:03 bell mpd: [L1-1] LCP: rec'd Protocol Reject #1 (Opened)
Mar 18 16:25:03 bell mpd: [L1-1] LCP: protocol CCP was rejected
Mar 18 16:25:03 bell mpd: [B1-1] CCP: protocol was rejected by peer
Mar 18 16:25:03 bell mpd: [B1-1] CCP: state change Req-Sent --> Stopped
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "CCP" FsmTimeout() at
fsm.c:190
Mar 18 16:25:03 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() at timer.c:83
Mar 18 16:25:03 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() done at timer.c:83
Mar 18 16:25:03 bell mpd: [B1-1] CCP: LayerFinish
Mar 18 16:25:03 bell mpd: [B1-1] rec'd 16 bytes bypass frame link=0
proto=0x8021
Mar 18 16:25:03 bell mpd: 01 02 00 10 03 06 c0 a8 00 2a 02 06 00 2d
0f 00 .........*...-..
Mar 18 16:25:03 bell mpd: [B1-1] IPCP: rec'd Configure Request #2 (Ack-Rcvd)
Mar 18 16:25:03 bell mpd: [B1-1] IPADDR 192.168.0.42
Mar 18 16:25:03 bell mpd: [B1-1] 192.168.0.42 is OK
Mar 18 16:25:03 bell mpd: [B1-1] COMPPROTO VJCOMP, 16 comp. channels,
no comp-cid
Mar 18 16:25:03 bell mpd: [B1-1] IPCP: SendConfigAck #2
Mar 18 16:25:03 bell mpd: [B1-1] IPADDR 192.168.0.42
Mar 18 16:25:03 bell mpd: [B1-1] COMPPROTO VJCOMP, 16 comp. channels,
no comp-cid
Mar 18 16:25:03 bell mpd: [B1-1] xmit bypass frame link=-1 proto=0x8021
Mar 18 16:25:03 bell mpd: ff ff 80 21 02 02 00 10 03 06 c0 a8 00 2a
02 06 ...!.........*..
Mar 18 16:25:03 bell mpd: 00 2d 0f
00 .-..
Mar 18 16:25:03 bell mpd: [B1-1] IPCP: state change Ack-Rcvd --> Opened
Mar 18 16:25:03 bell mpd: EVENT: Stopping timer "IPCP" FsmTimeout() at
fsm.c:190
Mar 18 16:25:03 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() at timer.c:83
Mar 18 16:25:03 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() done at timer.c:83
Mar 18 16:25:03 bell mpd: [B1-1] IPCP: LayerUp
Mar 18 16:25:03 bell mpd: [B1-1] 192.168.0.40 -> 192.168.0.42
Mar 18 16:25:03 bell mpd: [B1-1] IFACE: Connecting tcpmssfix
Mar 18 16:25:03 bell mpd: [B1-1] IFACE: Add address
192.168.0.40/32->192.168.0.42 to ng0
Mar 18 16:25:03 bell mpd: [B1-1] IFACE: Up event
Mar 18 16:25:03 bell mpd: [B1-1] IFACE: idle-timeout: 1800 seconds
Mar 18 16:25:03 bell mpd: EVENT: Starting timer "IfaceIdle"
IfaceIdleTimeout() for 450000 ms at iface.c:409
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() at timer.c:50
Mar 18 16:25:03 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() done at timer.c:50
Mar 18 16:25:03 bell mpd: [B1-1] IFACE: Change interface flags: -0 +1
Mar 18 16:25:03 bell mpd: EVENT: Processing event EVENT_READ
LinkNgDataEvent() done
Mar 18 16:25:09 bell mpd: EVENT: Processing event EVENT_TIMEOUT
TimerExpires()
Mar 18 16:25:09 bell mpd: EVENT: Processing timer "FsmKeepAlive"
FsmEchoTimeout()
Mar 18 16:25:09 bell mpd: EVENT: Processing timer "FsmKeepAlive"
FsmEchoTimeout() done
Mar 18 16:25:09 bell mpd: EVENT: Processing event EVENT_TIMEOUT
TimerExpires() done
Mar 18 16:25:14 bell mpd: EVENT: Processing event EVENT_TIMEOUT
TimerExpires()
Mar 18 16:25:14 bell mpd: EVENT: Processing timer "FsmKeepAlive"
FsmEchoTimeout()
Mar 18 16:25:14 bell mpd: [L1-1] LCP: SendEchoReq #1
Mar 18 16:25:14 bell mpd: [B1-1] xmit bypass frame link=0 proto=0xc021
Mar 18 16:25:14 bell mpd: 00 00 c0 21 09 01 00 08 bd f7 07
21 ...!.......!
Mar 18 16:25:14 bell mpd: EVENT: Processing timer "FsmKeepAlive"
FsmEchoTimeout() done
Mar 18 16:25:14 bell mpd: EVENT: Processing event EVENT_TIMEOUT
TimerExpires() done
Mar 18 16:25:19 bell mpd: EVENT: Processing event EVENT_TIMEOUT
TimerExpires()
Mar 18 16:25:19 bell mpd: EVENT: Processing timer "FsmKeepAlive"
FsmEchoTimeout()
Mar 18 16:25:19 bell mpd: [L1-1] LCP: no reply to 1 echo request(s)
Mar 18 16:25:19 bell mpd: [L1-1] LCP: SendEchoReq #2
Mar 18 16:25:19 bell mpd: [B1-1] xmit bypass frame link=0 proto=0xc021
Mar 18 16:25:19 bell mpd: 00 00 c0 21 09 02 00 08 bd f7 07
21 ...!.......!
Mar 18 16:25:19 bell mpd: EVENT: Processing timer "FsmKeepAlive"
FsmEchoTimeout() done
Mar 18 16:25:19 bell mpd: EVENT: Processing event EVENT_TIMEOUT
TimerExpires() done
Mar 18 16:25:24 bell mpd: EVENT: Processing event EVENT_TIMEOUT
TimerExpires()
Mar 18 16:25:24 bell mpd: EVENT: Processing timer "FsmKeepAlive"
FsmEchoTimeout()
Mar 18 16:25:24 bell mpd: [L1-1] LCP: no reply to 2 echo request(s)
Mar 18 16:25:24 bell mpd: [L1-1] LCP: SendEchoReq #3
Mar 18 16:25:24 bell mpd: [B1-1] xmit bypass frame link=0 proto=0xc021
Mar 18 16:25:24 bell mpd: 00 00 c0 21 09 03 00 08 bd f7 07
21 ...!.......!
Mar 18 16:25:24 bell mpd: EVENT: Processing timer "FsmKeepAlive"
FsmEchoTimeout() done
Mar 18 16:25:24 bell mpd: EVENT: Processing event EVENT_TIMEOUT
TimerExpires() done
Mar 18 16:25:24 bell mpd: L2TP: RECV [MESSAGE_TYPE StopCCN]
[ASSIGNED_TUNNEL_ID 0x149f] [RESULT_CODE result=6 error=0 errmsg=""]
Mar 18 16:25:24 bell mpd: L2TP: rec'd StopCCN in state established
Mar 18 16:25:24 bell mpd: [L1-1] L2TP: call #8630000 terminated:
result=2 error=6 errmsg="control connection closing"
Mar 18 16:25:24 bell mpd: [L1-1] device: DOWN event
Mar 18 16:25:24 bell mpd: [L1-1] Link: DOWN event
Mar 18 16:25:24 bell mpd: [L1-1] LCP: Close event
Mar 18 16:25:24 bell mpd: [L1-1] LCP: state change Opened --> Closing
Mar 18 16:25:24 bell mpd: [L1-1] LCP: phase shift NETWORK --> TERMINATE
Mar 18 16:25:24 bell mpd: [L1-1] Link: Leave bundle "B1-1"
Mar 18 16:25:24 bell mpd: [L1-1] ACCT: Accounting data for user
'<username>': 23 seconds, 50 octets in, 90 octets out
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "(null)" (null)() at
auth.c:879
Mar 18 16:25:24 bell mpd: [B1-1] IFACE: setting ng0 MTU to 1500 bytes
Mar 18 16:25:24 bell mpd: [B1-1] Bundle: Status update: up 0 links,
total bandwidth 9600 bps
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "(null)" (null)() at
bund.c:1495
Mar 18 16:25:24 bell mpd: [B1-1] IPCP: Close event
Mar 18 16:25:24 bell mpd: [B1-1] IPCP: state change Opened --> Closing
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "(null)" (null)() at
fsm.c:194
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "IPCP" FsmTimeout() at
fsm.c:531
Mar 18 16:25:24 bell mpd: [B1-1] IPCP: SendTerminateReq #2
Mar 18 16:25:24 bell mpd: [B1-1] xmit bypass frame link=-1 proto=0x8021
Mar 18 16:25:24 bell mpd: ff ff 80 21 05 02 00
04 ...!....
Mar 18 16:25:24 bell mpd: [B1-1] Bundle: No links ready to send packet
Mar 18 16:25:24 bell mpd: EVENT: Starting timer "IPCP" FsmTimeout() for
2000 ms at fsm.c:438
Mar 18 16:25:24 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() at timer.c:50
Mar 18 16:25:24 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() done at timer.c:50
Mar 18 16:25:24 bell mpd: [B1-1] IPCP: LayerDown
Mar 18 16:25:24 bell mpd: [B1-1] IFACE: Remove address
192.168.0.40/32->192.168.0.42 from ng0
Mar 18 16:25:24 bell mpd: [B1-1] IFACE: Down event
Mar 18 16:25:24 bell mpd: [B1-1] IFACE: Change interface flags: -4097 +0
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "IfaceIdle"
IfaceIdleTimeout() at iface.c:523
Mar 18 16:25:24 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() at timer.c:83
Mar 18 16:25:24 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() done at timer.c:83
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "(null)" (null)() at
iface.c:524
Mar 18 16:25:24 bell mpd: [B1-1] CCP: Close event
Mar 18 16:25:24 bell mpd: [B1-1] CCP: state change Stopped --> Closed
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "CCP" FsmTimeout() at
fsm.c:190
Mar 18 16:25:24 bell mpd: [B1-1] IPCP: Down event
Mar 18 16:25:24 bell mpd: [B1-1] IPCP: LayerFinish
Mar 18 16:25:24 bell mpd: [B1-1] Bundle: No NCPs left. Closing links...
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "(null)" (null)() at
bund.c:619
Mar 18 16:25:24 bell mpd: [B1-1] IPCP: state change Closing --> Initial
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "IPCP" FsmTimeout() at
fsm.c:190
Mar 18 16:25:24 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() at timer.c:83
Mar 18 16:25:24 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() done at timer.c:83
Mar 18 16:25:24 bell mpd: [B1-1] CCP: Down event
Mar 18 16:25:24 bell mpd: [B1-1] CCP: state change Closed --> Initial
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "CCP" FsmTimeout() at
fsm.c:190
Mar 18 16:25:24 bell mpd: [B1-1] Bundle: Shutdown
Mar 18 16:25:24 bell mpd: [L1-1] AUTH: Cleanup
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "FsmKeepAlive"
FsmEchoTimeout() at fsm.c:194
Mar 18 16:25:24 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() at timer.c:83
Mar 18 16:25:24 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() done at timer.c:83
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "LCP" FsmTimeout() at
fsm.c:531
Mar 18 16:25:24 bell mpd: [L1-1] LCP: SendTerminateReq #4
Mar 18 16:25:24 bell mpd: [L1-1] xmit frame to link proto=0xc021
Mar 18 16:25:24 bell mpd: ff 03 c0 21 05 04 00
04 ...!....
Mar 18 16:25:24 bell mpd: [L1-1] Link: Not ready to send packet
Mar 18 16:25:24 bell mpd: EVENT: Starting timer "LCP" FsmTimeout() for
2000 ms at fsm.c:438
Mar 18 16:25:24 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() at timer.c:50
Mar 18 16:25:24 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() done at timer.c:50
Mar 18 16:25:24 bell mpd: [L1-1] LCP: LayerDown
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "AuthTimer"
AuthTimeout() at auth.c:682
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "(null)" (null)() at
pap.c:64
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "ChalTimer"
ChapChalTimeout() at chap.c:93
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "(null)" (null)() at
chap.c:94
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "(null)" (null)() at
eap.c:146
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "(null)" (null)() at
eap.c:147
Mar 18 16:25:24 bell mpd: [L1-1] LCP: Down event
Mar 18 16:25:24 bell mpd: [L1-1] LCP: LayerFinish
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "AuthTimer"
AuthTimeout() at auth.c:682
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "(null)" (null)() at
pap.c:64
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "ChalTimer"
ChapChalTimeout() at chap.c:93
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "(null)" (null)() at
chap.c:94
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "(null)" (null)() at
eap.c:146
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "(null)" (null)() at
eap.c:147
Mar 18 16:25:24 bell mpd: EVENT: Message 2 to PhysMsg() sent
Mar 18 16:25:24 bell mpd: [L1-1] LCP: state change Closing --> Initial
Mar 18 16:25:24 bell mpd: [L1-1] LCP: phase shift TERMINATE --> DEAD
Mar 18 16:25:24 bell mpd: EVENT: Message 5 to LinkMsg() sent
Mar 18 16:25:24 bell mpd: EVENT: Stopping timer "LCP" FsmTimeout() at
fsm.c:190
Mar 18 16:25:24 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() at timer.c:83
Mar 18 16:25:24 bell mpd: EVENT: Unregistering event EVENT_TIMEOUT
TimerExpires() done at timer.c:83
Mar 18 16:25:24 bell mpd: EVENT: Message 5 to LinkMsg() sent
Mar 18 16:25:24 bell mpd: L2TP: Control connection 0x286f3d08
terminated: 0 ()
Mar 18 16:25:24 bell mpd: EVENT: Processing event EVENT_READ MsgEvent()
Mar 18 16:25:24 bell mpd: EVENT: Message 2 to PhysMsg() received
Mar 18 16:25:24 bell mpd: [L1-1] device: CLOSE event
Mar 18 16:25:24 bell mpd: EVENT: Message 2 to PhysMsg() processed
Mar 18 16:25:24 bell mpd: EVENT: Message 5 to LinkMsg() received
Mar 18 16:25:24 bell mpd: [L1-1] Link: SHUTDOWN event
Mar 18 16:25:24 bell mpd: [L1-1] Link: Shutdown
Mar 18 16:25:24 bell mpd: EVENT: Message 5 to LinkMsg() processed
Mar 18 16:25:24 bell mpd: EVENT: Message 5 to LinkMsg() received
Mar 18 16:25:24 bell mpd: EVENT: Message 5 to LinkMsg() processed
Mar 18 16:25:24 bell mpd: EVENT: Processing event EVENT_READ MsgEvent() done
Mar 18 16:25:26 bell mpd: EVENT: Processing event EVENT_READ SignalHandler()
Mar 18 16:25:26 bell mpd: caught fatal signal term
Mar 18 16:25:26 bell mpd: EVENT: Starting timer "DeathTimer" (void
(*)(void *)) DoExit() for 2000 ms at main.c:478
Mar 18 16:25:26 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() at timer.c:50
Mar 18 16:25:26 bell mpd: EVENT: Registering event EVENT_TIMEOUT
TimerExpires() done at timer.c:50
Mar 18 16:25:26 bell mpd: EVENT: Processing event EVENT_READ
SignalHandler() done
Mar 18 16:25:28 bell mpd: EVENT: Processing event EVENT_TIMEOUT
TimerExpires()
Mar 18 16:25:28 bell mpd: EVENT: Processing timer "DeathTimer" (void
(*)(void *)) DoExit()
Mar 18 16:25:28 bell mpd: [B1] Bundle: Shutdown
Mar 18 16:25:28 bell mpd: [L1] Link: Shutdown
Mar 18 16:25:28 bell mpd: L2TP: stop waiting for connection on 0.0.0.0 1701
Mar 18 16:25:28 bell mpd: EVENT: Unregistering event EVENT_READ
L2tpServerEvent() at l2tp.c:1671
Mar 18 16:25:28 bell mpd: EVENT: Unregistering event EVENT_READ
L2tpServerEvent() done at l2tp.c:1671
Mar 18 16:25:28 bell mpd: PPTP: Total shutdown
Mar 18 16:25:28 bell mpd: L2TP: Total shutdown
Mar 18 16:25:28 bell mpd: EVENT: Unregistering event EVENT_READ
EcpNgDataEvent() at ecp.c:193
Mar 18 16:25:28 bell mpd: EVENT: Unregistering event EVENT_READ
EcpNgDataEvent() done at ecp.c:193
Mar 18 16:25:28 bell mpd: EVENT: Unregistering event EVENT_READ
CcpNgCtrlEvent() at ccp.c:190
Mar 18 16:25:28 bell mpd: EVENT: Unregistering event EVENT_READ
CcpNgCtrlEvent() done at ccp.c:190
Mar 18 16:25:28 bell mpd: EVENT: Unregistering event EVENT_READ
CcpNgDataEvent() at ccp.c:193
Mar 18 16:25:28 bell mpd: EVENT: Unregistering event EVENT_READ
CcpNgDataEvent() done at ccp.c:193
Mar 18 16:25:28 bell mpd: EVENT: Unregistering event EVENT_READ
LinkNgDataEvent() at link.c:182
Mar 18 16:25:28 bell mpd: EVENT: Unregistering event EVENT_READ
LinkNgDataEvent() done at link.c:182
Mar 18 16:25:28 bell mpd: process 18243 terminated
Ok. So I have a connection, and I've answered a couple of my own
questions. I posted all this for future reference to show a working
connection log.
Still a few questions to clear up:
First, the connection from Android (apparently uses mtpd- I just found
out) fails at SCCRP- apparently it doesn't respond to the challenge
response (logs posted previously). Using xl2tpd (apparently- linux only)
you have a l2tp-secrets file with the local hostname, remote hostname,
and the secret in that order. How do I do this in mpd? I tried the
hostname directive, but its still no good. Or is this never going to
work with mpd? Just use it without secrets?
Second, why does mpd die (as in terminated- no process running) when
this fails?
Cheers
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?4D833787.3020706>