[Openswan Users] PPP issues (was Re: openswan + l2tpd + iptables problem)
mechanix at debian.org
mechanix at debian.org
Thu Oct 19 13:03:48 EDT 2006
On Thu, Oct 19, 2006 at 12:50:31AM +0200, mechanix at debian.org wrote:
> On Wed, Oct 18, 2006 at 11:23:15PM +0200, Jacco de Leeuw wrote:
> >
> > Filip wrote:
> > >
> > >I took a closer look at the logs, and it seems that the pppd mtu option
> > >from the configuration file is simply ignored. The client asks for a mru
> > >of 1400, and pppd just acknowledges that, and then possibly starts sending
> > >packets which are to big and do not get through.
> >
> > I'm not so sure about that because the PPP negotiation almost completes.
> > The main differences between your two logs is that the BE client gives up
> > CCP negotiation after the server says it does not support MPPE and
> > compression also does not complete.
>
> I ran tcpdump while noccp and require-mppe were both not set in the
> options.l2tp file; and got udp-encap traffic both ways initially, then
> only incoming messages for a while until traffic halted. Seems to confirm
> my suspicion.
I superficially checked the pppd LCP code, and it looks like the actual
MTU used is not what is returned to the client as MRU but what was
configured (that is, if the requested client MRU was smaller than
configured server MTU). So that would not be the problem indeed.
I also lowered mtu setting in the options file and it had in fact an
effect - for example, when I set 1100 or lower CHAP authentication no
longer succeeded.
I discovered something else: when I run tcpdump on the gateway, it seems
to `forget' how to reach the client - which seems to coincide with the
moment packets stop getting sent to the client - seeing that it performs
arp requests, which are never answered.
Does anyone know what could be up with that?
Tcpdump output and l2tpd/pppd log follow. (sample session where I had
removed the noccp and require-mppe options; broken up after 20 seconds of
negotiation on the client counter)
22:57:39.299350 IP REM.OTE.ADDR.ESS.500 > GW.IP.ADDR.ESS.500: isakmp: phase 1 I ident
22:57:39.299799 IP GW.IP.ADDR.ESS.500 > REM.OTE.ADDR.ESS.500: isakmp: phase 1 R ident
22:57:40.184423 IP REM.OTE.ADDR.ESS.500 > GW.IP.ADDR.ESS.500: isakmp: phase 1 I ident
22:57:40.184696 IP GW.IP.ADDR.ESS.500 > REM.OTE.ADDR.ESS.500: isakmp: phase 1 R ident
22:57:40.878496 IP REM.OTE.ADDR.ESS.500 > GW.IP.ADDR.ESS.500: isakmp: phase 1 I ident
22:57:40.887020 IP GW.IP.ADDR.ESS.500 > REM.OTE.ADDR.ESS.500: isakmp: phase 1 R ident
22:57:41.375874 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: NONESP-encap: isakmp: phase 1 I ident[E]
22:57:41.379031 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: NONESP-encap: isakmp: phase 1 R ident[E]
22:57:41.792612 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: NONESP-encap: isakmp: phase 2/others I oakley-quick[E]
22:57:41.793165 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: NONESP-encap: isakmp: phase 2/others R oakley-quick[E]
22:57:42.174675 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: NONESP-encap: isakmp: phase 2/others I oakley-quick[E]
22:57:42.181077 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x1), length 156
22:57:42.181901 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0x1), length 140
22:57:42.564183 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x2), length 60
22:57:42.564449 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0x2), length 52
22:57:42.565686 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x3), length 92
22:57:42.566039 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0x3), length 68
22:57:42.566057 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0x4), length 52
22:57:42.566389 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x4), length 52
22:57:42.949055 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x5), length 92
22:57:42.949567 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x6), length 52
22:57:42.952543 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0x5), length 52
22:57:42.953508 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0x6), length 84
22:57:42.958931 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x7), length 100
22:57:42.960782 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0x7), length 68
22:57:43.334166 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x8), length 84
22:57:43.338591 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x9), length 92
22:57:43.338915 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0x8), length 92
22:57:43.338934 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0x9), length 60
22:57:43.338951 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0xa), length 76
22:57:43.728661 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0xa), length 68
22:57:43.730141 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0xb), length 76
22:57:43.731347 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0xc), length 60
22:57:43.733123 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0xd), length 124
22:57:43.760381 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0xb), length 116
22:57:43.760405 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0xc), length 68
22:57:43.760422 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0xd), length 68
22:57:44.143634 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0xe), length 60
22:57:44.143870 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0xe), length 60
22:57:44.145516 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0xf), length 84
22:57:44.145728 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0xf), length 68
22:57:44.146047 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x10), length 68
22:57:44.146242 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0x10), length 52
22:57:44.147265 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x11), length 60
22:57:44.147459 IP GW.IP.ADDR.ESS.4500 > REM.OTE.ADDR.ESS.4500: UDP-encap: ESP(spi=0xb1f325b8,seq=0x11), length 60
22:57:44.266963 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:57:44.527465 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x12), length 68
22:57:44.533130 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x13), length 76
22:57:44.534593 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x14), length 60
22:57:45.267072 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:57:45.969884 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x15), length 76
22:57:45.971079 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x16), length 68
22:57:46.267167 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:57:48.969962 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x17), length 76
22:57:48.975399 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:57:49.975476 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:57:50.975562 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:57:52.968155 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x18), length 76
22:57:52.971729 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:57:53.971813 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:57:54.971899 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:57:56.156000 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:57:56.970535 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x19), length 76
22:57:57.156083 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:57:58.156169 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:57:59.160257 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:00.160342 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:00.968037 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x1a), length 60
22:58:01.160420 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:02.164532 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:02.171852 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: isakmp-nat-keep-alive
22:58:03.164608 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:04.034606 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x1b), length 68
22:58:04.164695 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:07.064947 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:07.986767 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x1c), length 68
22:58:08.065052 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:09.065128 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:10.069231 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:11.069300 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:11.984414 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x1d), length 76
22:58:12.069395 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:14.069559 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:15.069654 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:16.069731 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:21.983264 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: UDP-encap: ESP(spi=0x537cb518,seq=0x1e), length 76
22:58:21.988148 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: NONESP-encap: isakmp: phase 2/others I inf[E]
22:58:21.994196 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:22.003428 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: NONESP-encap: isakmp: phase 2/others I inf[E]
22:58:22.169489 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: isakmp-nat-keep-alive
22:58:22.994387 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:23.994454 arp who-has REM.OTE.ADDR.ESS tell GW.IP.ADDR.ESS
22:58:31.997870 IP REM.OTE.ADDR.ESS.1701 > GW.IP.ADDR.ESS.1701: l2tp:[TLS](12824/23391)Ns=4,Nr=2 *MSGTYPE(CDN) *RESULT_CODE(3/0) *ASSND_SESS_ID(1)
22:58:41.996696 IP REM.OTE.ADDR.ESS.1701 > GW.IP.ADDR.ESS.1701: l2tp:[TLS](12824/23391)Ns=4,Nr=2 *MSGTYPE(CDN) *RESULT_CODE(3/0) *ASSND_SESS_ID(1)
22:58:42.172376 IP REM.OTE.ADDR.ESS.4500 > GW.IP.ADDR.ESS.4500: isakmp-nat-keep-alive
22:58:51.995306 IP REM.OTE.ADDR.ESS.1701 > GW.IP.ADDR.ESS.1701: l2tp:[TLS](12824/23391)Ns=4,Nr=2 *MSGTYPE(CDN) *RESULT_CODE(3/0) *ASSND_SESS_ID(1)
22:58:53.371659 IP REM.OTE.ADDR.ESS.1701 > GW.IP.ADDR.ESS.1701: l2tp:[TLS](12824/23391)Ns=4,Nr=2 *MSGTYPE(CDN) *RESULT_CODE(3/0) *ASSND_SESS_ID(1)
Oct 19 22:57:42 scotos l2tpd[20820]: ourtid = 12824, entropy_buf = 3218
Oct 19 22:57:42 scotos l2tpd[20820]: ourcid = 63129, entropy_buf = f699
Oct 19 22:57:42 scotos l2tpd[20820]: check_control: control, cid = 0, Ns = 0, Nr = 0
Oct 19 22:57:42 scotos l2tpd[20820]: handle_avps: handling avp's for tunnel 12824, call 63129
Oct 19 22:57:42 scotos l2tpd[20820]: message_type_avp: message type 1 (Start-Control-Connection-Request)
Oct 19 22:57:42 scotos l2tpd[20820]: protocol_version_avp: peer is using version 1, revision 0.
Oct 19 22:57:42 scotos l2tpd[20820]: framing_caps_avp: supported peer frames: sync
Oct 19 22:57:42 scotos l2tpd[20820]: bearer_caps_avp: supported peer bearers:
Oct 19 22:57:42 scotos l2tpd[20820]: firmware_rev_avp: peer reports firmware version 1280 (0x0500)
Oct 19 22:57:42 scotos l2tpd[20820]: hostname_avp: peer reports hostname 'sisyphos.qbian.local'
Oct 19 22:57:42 scotos l2tpd[20820]: vendor_avp: peer reports vendor 'Microsoft'
Oct 19 22:57:42 scotos l2tpd[20820]: assigned_tunnel_avp: using peer's tunnel 18
Oct 19 22:57:42 scotos l2tpd[20820]: receive_window_size_avp: peer wants RWS of 8. Will use flow control.
Oct 19 22:57:42 scotos l2tpd[20820]: check_control: control, cid = 0, Ns = 1, Nr = 1
Oct 19 22:57:42 scotos l2tpd[20820]: handle_avps: handling avp's for tunnel 12824, call 63129
Oct 19 22:57:42 scotos l2tpd[20820]: message_type_avp: message type 3 (Start-Control-Connection-Connected)
Oct 19 22:57:42 scotos l2tpd[20820]: check_control: control, cid = 0, Ns = 2, Nr = 1
Oct 19 22:57:42 scotos l2tpd[20820]: handle_avps: handling avp's for tunnel 12824, call 63129
Oct 19 22:57:42 scotos l2tpd[20820]: message_type_avp: message type 10 (Incoming-Call-Request)
Oct 19 22:57:42 scotos l2tpd[20820]: message_type_avp: new incoming call
Oct 19 22:57:42 scotos l2tpd[20820]: ourcid = 23391, entropy_buf = 5b5f
Oct 19 22:57:42 scotos l2tpd[20820]: assigned_session_avp: assigned session id: 1
Oct 19 22:57:42 scotos l2tpd[20820]: call_serno_avp: serial number is 0
Oct 19 22:57:42 scotos l2tpd[20820]: bearer_type_avp: peer bears: analog
Oct 19 22:57:42 scotos l2tpd[20820]: check_control: control, cid = 0, Ns = 3, Nr = 1
Oct 19 22:57:42 scotos l2tpd[20820]: check_control: control, cid = 1, Ns = 3, Nr = 2
Oct 19 22:57:42 scotos l2tpd[20820]: handle_avps: handling avp's for tunnel 12824, call 23391
Oct 19 22:57:42 scotos l2tpd[20820]: message_type_avp: message type 12 (Incoming-Call-Connected)
Oct 19 22:57:42 scotos l2tpd[20820]: tx_speed_avp: transmit baud rate is 100000000
Oct 19 22:57:42 scotos l2tpd[20820]: frame_type_avp: peer uses:sync frames
Oct 19 22:57:42 scotos l2tpd[20820]: ignore_avp : Ignoring AVP
Oct 19 22:57:42 scotos l2tpd[20820]: start_pppd: I'm running:
Oct 19 22:57:42 scotos l2tpd[20820]: "/usr/sbin/pppd"
Oct 19 22:57:42 scotos l2tpd[20820]: "passive"
Oct 19 22:57:42 scotos l2tpd[20820]: "-detach"
Oct 19 22:57:42 scotos l2tpd[20820]: "192.168.2.254:192.168.2.201"
Oct 19 22:57:42 scotos l2tpd[20820]: "auth"
Oct 19 22:57:42 scotos l2tpd[20820]: "name"
Oct 19 22:57:42 scotos l2tpd[20820]: "scotos"
Oct 19 22:57:42 scotos l2tpd[20820]: "debug"
Oct 19 22:57:42 scotos l2tpd[20820]: "file"
Oct 19 22:57:42 scotos l2tpd[20820]: "/etc/ppp/options.l2tpd.lns"
Oct 19 22:57:42 scotos l2tpd[20820]: "/dev/ttyp0"
Oct 19 22:57:42 scotos l2tpd[20820]:
Oct 19 22:57:42 scotos l2tpd[20820]: check_control: control, cid = 0, Ns = 4, Nr = 2
Oct 19 22:57:42 scotos pppd[24338]: using channel 46
Oct 19 22:57:42 scotos pppd[24338]: sent [LCP ConfReq id=0x1 <mru 1360> <asyncmap 0x0> <auth chap MS-v2> <magic 0x6a9d997> <pcomp> <accomp>]
Oct 19 22:57:42 scotos pppd[24338]: rcvd [LCP ConfReq id=0x0 <mru 1400> <magic 0x15241696> <pcomp> <accomp> <callback CBCP> <mrru 1614> <endpoint [local:e4.f2.0a.21.ea.1e.40.c9.bc.4d.ee.ae.42.7b.8a.70.00.00.00.03]>]
Oct 19 22:57:42 scotos pppd[24338]: sent [LCP ConfRej id=0x0 <callback CBCP> <mrru 1614>]
Oct 19 22:57:43 scotos pppd[24338]: rcvd [LCP ConfAck id=0x1 <mru 1360> <asyncmap 0x0> <auth chap MS-v2> <magic 0x6a9d997> <pcomp> <accomp>]
Oct 19 22:57:43 scotos pppd[24338]: rcvd [LCP ConfReq id=0x1 <mru 1400> <magic 0x15241696> <pcomp> <accomp> <endpoint [local:e4.f2.0a.21.ea.1e.40.c9.bc.4d.ee.ae.42.7b.8a.70.00.00.00.03]>]
Oct 19 22:57:43 scotos pppd[24338]: sent [LCP ConfAck id=0x1 <mru 1400> <magic 0x15241696> <pcomp> <accomp> <endpoint [local:e4.f2.0a.21.ea.1e.40.c9.bc.4d.ee.ae.42.7b.8a.70.00.00.00.03]>]
Oct 19 22:57:43 scotos pppd[24338]: sent [LCP EchoReq id=0x0 magic=0x6a9d997]
Oct 19 22:57:43 scotos pppd[24338]: sent [CHAP Challenge id=0x41 <807e2a91d33322aefec428b6ad54e834>, name = "scotos"]
Oct 19 22:57:43 scotos pppd[24338]: rcvd [LCP Ident id=0x2 magic=0x15241696 "MSRASV5.10"]
Oct 19 22:57:43 scotos pppd[24338]: rcvd [LCP Ident id=0x3 magic=0x15241696 "MSRAS-0-SISYPHOS"]
Oct 19 22:57:43 scotos pppd[24338]: rcvd [LCP EchoRep id=0x0 magic=0x15241696]
Oct 19 22:57:43 scotos pppd[24338]: rcvd [CHAP Response id=0x41 <94e0866c75d2925d97993a5a84d71b990000000000000000b288484f3e6ff66516c635c621b22712949ed4d56a18f19900>, name = "DOMAIN\\username"]
Oct 19 22:57:43 scotos pppd[24338]: sent [CHAP Success id=0x41 "S=C4512B00156AF79E965EA2671C0B73E07F04E33C M=Access granted"]
Oct 19 22:57:43 scotos pppd[24338]: sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Oct 19 22:57:43 scotos pppd[24338]: sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 192.168.2.254>]
Oct 19 22:57:44 scotos pppd[24338]: rcvd [CCP ConfReq id=0x4 <mppe +H -M -S -L -D +C>]
Oct 19 22:57:44 scotos pppd[24338]: sent [CCP ConfRej id=0x4 <mppe +H -M -S -L -D +C>]
Oct 19 22:57:44 scotos pppd[24338]: rcvd [IPCP ConfReq id=0x5 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-wins 0.0.0.0> <ms-dns3 0.0.0.0> <ms-wins 0.0.0.0>]
Oct 19 22:57:44 scotos pppd[24338]: sent [IPCP ConfRej id=0x5 <ms-wins 0.0.0.0> <ms-wins 0.0.0.0>]
Oct 19 22:57:44 scotos pppd[24338]: rcvd [CCP ConfRej id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]
Oct 19 22:57:44 scotos pppd[24338]: sent [CCP ConfReq id=0x2]
Oct 19 22:57:44 scotos pppd[24338]: rcvd [IPCP ConfRej id=0x1 <compress VJ 0f 01>]
Oct 19 22:57:44 scotos pppd[24338]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 19 22:57:44 scotos pppd[24338]: rcvd [CCP TermReq id=0x6 15 24 16 96 00 3c cd 74 00 00 02 dc]
Oct 19 22:57:44 scotos pppd[24338]: sent [CCP TermAck id=0x6]
Oct 19 22:57:44 scotos pppd[24338]: rcvd [IPCP ConfReq id=0x7 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Oct 19 22:57:44 scotos pppd[24338]: sent [IPCP ConfNak id=0x7 <addr 192.168.2.201> <ms-dns1 192.168.2.254> <ms-dns3 192.168.2.254>]
Oct 19 22:57:44 scotos pppd[24338]: rcvd [IPCP ConfAck id=0x2 <addr 192.168.2.254>]
Oct 19 22:57:45 scotos pppd[24338]: rcvd [IPCP ConfReq id=0x8 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Oct 19 22:57:45 scotos pppd[24338]: sent [IPCP ConfNak id=0x8 <addr 192.168.2.201> <ms-dns1 192.168.2.254> <ms-dns3 192.168.2.254>]
Oct 19 22:57:45 scotos pppd[24338]: rcvd [CCP TermReq id=0x9 15 24 16 96 00 3c cd 74 00 00 02 dc]
Oct 19 22:57:45 scotos pppd[24338]: sent [CCP TermAck id=0x9]
Oct 19 22:57:47 scotos pppd[24338]: sent [CCP ConfReq id=0x2]
Oct 19 22:57:47 scotos pppd[24338]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 19 22:57:48 scotos pppd[24338]: rcvd [IPCP ConfReq id=0xa <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Oct 19 22:57:48 scotos pppd[24338]: sent [IPCP ConfNak id=0xa <addr 192.168.2.201> <ms-dns1 192.168.2.254> <ms-dns3 192.168.2.254>]
Oct 19 22:57:50 scotos pppd[24338]: sent [CCP ConfReq id=0x2]
Oct 19 22:57:50 scotos pppd[24338]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 19 22:57:52 scotos pppd[24338]: rcvd [IPCP ConfReq id=0xb <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Oct 19 22:57:52 scotos pppd[24338]: sent [IPCP ConfNak id=0xb <addr 192.168.2.201> <ms-dns1 192.168.2.254> <ms-dns3 192.168.2.254>]
Oct 19 22:57:53 scotos pppd[24338]: sent [CCP ConfReq id=0x2]
Oct 19 22:57:53 scotos pppd[24338]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 19 22:57:56 scotos pppd[24338]: sent [CCP ConfReq id=0x2]
Oct 19 22:57:56 scotos pppd[24338]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 19 22:57:56 scotos pppd[24338]: rcvd [IPCP ConfReq id=0xc <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]
Oct 19 22:57:56 scotos pppd[24338]: sent [IPCP ConfNak id=0xc <addr 192.168.2.201> <ms-dns1 192.168.2.254> <ms-dns3 192.168.2.254>]
Oct 19 22:57:59 scotos pppd[24338]: sent [CCP ConfReq id=0x2]
Oct 19 22:57:59 scotos pppd[24338]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 19 22:58:00 scotos pppd[24338]: rcvd [IPCP ConfReq id=0xd <addr 0.0.0.0>]
Oct 19 22:58:00 scotos pppd[24338]: sent [IPCP ConfRej id=0xd <addr 0.0.0.0>]
Oct 19 22:58:02 scotos pppd[24338]: sent [CCP ConfReq id=0x2]
Oct 19 22:58:02 scotos pppd[24338]: sent [IPCP ConfReq id=0x2 <addr 192.168.2.254>]
Oct 19 22:58:04 scotos pppd[24338]: rcvd [LCP TermReq id=0xe 15 24 16 96 00 3c cd 74 00 00 00 00]
Oct 19 22:58:04 scotos pppd[24338]: sent [LCP TermAck id=0xe]
Oct 19 22:58:07 scotos l2tpd[20820]: child_handler : pppd exited for call 1 with code 16
Oct 19 22:58:07 scotos l2tpd[20820]: write_packet: tty is not open yet.
Oct 19 22:58:11 scotos l2tpd[20820]: check_control: control, cid = 1, Ns = 4, Nr = 2
Oct 19 22:58:11 scotos l2tpd[20820]: handle_avps: handling avp's for tunnel 12824, call 23391
Oct 19 22:58:11 scotos l2tpd[20820]: message_type_avp: message type 14 (Call-Disconnect-Notify)
Oct 19 22:58:11 scotos l2tpd[20820]: result_code_avp: peer closing for reason 3 (Call disconnected for administrative reasons), error = 0 ()
Oct 19 22:58:11 scotos l2tpd[20820]: assigned_session_avp: assigned session id: 1
Oct 19 22:58:11 scotos l2tpd[20820]: control_finish: Peer tried to disconnect without specifying call ID
Oct 19 22:58:12 scotos l2tpd[20820]: control_xmit: Maximum retries exceeded for tunnel 12824. Closing.
Oct 19 22:58:17 scotos l2tpd[20820]: control_xmit: Unable to deliver closing message for tunnel 12824. Destroying anyway.
Oct 19 22:58:21 scotos l2tpd[20820]: get_call:can't find tunnel 12824
Oct 19 22:58:21 scotos l2tpd[20820]: network_thread: unable to find call or tunnel to handle packet. call = 23391, tunnel = 12824 Dumping.
Oct 19 22:58:31 scotos l2tpd[20820]: get_call:can't find tunnel 12824
Oct 19 22:58:31 scotos l2tpd[20820]: network_thread: unable to find call or tunnel to handle packet. call = 23391, tunnel = 12824 Dumping.
Oct 19 22:58:41 scotos l2tpd[20820]: get_call:can't find tunnel 12824
Oct 19 22:58:41 scotos l2tpd[20820]: network_thread: unable to find call or tunnel to handle packet. call = 23391, tunnel = 12824 Dumping.
Oct 19 22:58:51 scotos l2tpd[20820]: get_call:can't find tunnel 12824
Oct 19 22:58:51 scotos l2tpd[20820]: network_thread: unable to find call or tunnel to handle packet. call = 23391, tunnel = 12824 Dumping.
Oct 19 22:58:53 scotos l2tpd[20820]: get_call:can't find tunnel 12824
Oct 19 22:58:53 scotos l2tpd[20820]: network_thread: unable to find call or tunnel to handle packet. call = 23391, tunnel = 12824 Dumping.
Regards,
Filip
http://www.evonet.be/~filipvr/
More information about the Users
mailing list