It is currently Sun Sep 22, 2019 7:14 am

All times are UTC [ DST ]




Post new topic Reply to topic  [ 6 posts ] 
Author Message
 Post subject: Problem in establishing al L2TP tunnel between a linux serv
PostPosted: Fri Nov 13, 2009 9:31 pm 

Joined: Fri Nov 13, 2009 9:25 pm
Posts: 4
I'm trying to establish an L2TP/IPSec tunnel between a suse linux server and a windows XP client. I'v installed openL2TP 1.6 on the server side. The problem is that before the tunnel is established, it is disconnected by the peer.

linux-5u8g:/etc/ppp # openl2tpd -f -D
Start, trace_flags=00000000 (debug enabled)
OpenL2TP V1.6, (c) Copyright 2004,2005,2006,2007,2008 Katalix Systems Ltd.
Loading plugin /usr/lib/openl2tp/ppp_unix.so, version V1.5
Using config file: /etc/openl2tpd.conf
FUNC: tunl 51580: inherited ppp profile 'peer1' from peer profile
FUNC: tunl 51580: allocated context using profile 'default', created by network request
XPRT: RX: tunl 51580/0: len=109 ns/nr=0/0, our ns/nr=0/0, peer ns/nr=0/0
XPRT: tunl 51580: peer ns/nr is 0/0
DATA: RX: tunl 51580/0: rcv 109 bytes from peer 192.168.2.4, packet ns/nr 0/0 type 0
XPRT: tunl 51580: update nr from 0 to 1
AVP: tunl 51580: SCCRQ message decode of 89 bytes started
AVPDATA: PROTOCOL_VERSION: ver=1 rev=0
AVPDATA: FRAMING_CAP: cap=1
AVPDATA: BEARER_CAP: cap=0
AVPDATA: FIRMWARE_VERSION: revision=1280
AVPDATA: HOST_NAME: name=winClientMachine
AVPDATA: VENDOR_NAME: name=Microsoft
AVPDATA: TUNNEL_ID: id=28
AVPDATA: RX_WINDOW_SIZE: size=8
PROTO: tunl 51580: SCCRQ received from peer 28
FSM: CCE(51580) event SCCRQ_ACCEPT in state IDLE
PROTO: tunl 51580: adjust tx_window_size: peer=8, ours=10
AVP: tunl 51580: building SCCRP message, 9 AVPs
PROTO: tunl 51580: sending SCCRP to peer 28
XPRT: tunl 51580: queuing tx packet, type 2, len 146, ns/nr 0/1
XPRT: tunl 51580: update ns to 1
XPRT: tunl 51580: adding packet to ackq, type 2, len 146, ns/nr 0/1
DATA: TX: tunl 51580/0: send 146 bytes to peer 192.168.2.4, packet ns/nr 0/1 type 2, retry 0
FSM: CCE(51580) state change: IDLE --> WAITCTLCONN
XPRT: RX: tunl 51580/0: len=20 ns/nr=1/1, our ns/nr=1/1, peer ns/nr=0/0
XPRT: tunl 51580: peer ns/nr is 1/1
XPRT: tunl 51580: pkt 0/1 is acked by nr 1
DATA: RX: tunl 51580/0: rcv 20 bytes from peer 192.168.2.4, packet ns/nr 1/1 type 0
XPRT: tunl 51580: update nr from 1 to 2
AVP: tunl 51580: SCCCN message decode of 0 bytes started
PROTO: tunl 51580: SCCCN received from peer 28
FSM: CCE(51580) event SCCCN_ACCEPT in state WAITCTLCONN
FUNC: tunl 51580 up
FSM: CCE(51580) state change: WAITCTLCONN --> ESTABLISHED
XPRT: RX: tunl 51580/0: len=48 ns/nr=2/1, our ns/nr=1/2, peer ns/nr=1/1
XPRT: tunl 51580: peer ns/nr is 2/1
DATA: RX: tunl 51580/0: rcv 48 bytes from peer 192.168.2.4, packet ns/nr 2/1 type 0
XPRT: tunl 51580: update nr from 2 to 3
AVP: tunl 51580: ICRQ message decode of 28 bytes started
AVPDATA: SESSION_ID: id=1
AVPDATA: CALL_SERIAL_NUMBER: value=0
AVPDATA: BEARER_TYPE: type=2
PROTO: tunl 51580/0: ICRQ received from peer 28
51580/35394: creating UNIX pppd context
51580/35394: using ppp profile 'peer1'
FSM: LNIC(51580/35394) event ICRQ_ACCEPT in state IDLE
AVP: tunl 51580: building ICRP message, 2 AVPs
PROTO: tunl 51580/35394: sending ICRP to peer 28/1
XPRT: tunl 51580: queuing tx packet, type 11, len 28, ns/nr 1/3
XPRT: tunl 51580: update ns to 2
XPRT: tunl 51580: adding packet to ackq, type 11, len 28, ns/nr 1/3
DATA: TX: tunl 51580/1: send 28 bytes to peer 192.168.2.4, packet ns/nr 1/3 type 11, retry 0
FSM: LNIC(51580/35394) state change: IDLE --> WAITCONNECT
XPRT: RX: tunl 51580/0: len=12 ns/nr=3/1, our ns/nr=2/3, peer ns/nr=2/1
XPRT: tunl 51580: zlb ack received: ns/nr=3/1
XPRT: tunl 51580: peer ns/nr is 3/1
XPRT: RX: tunl 51580/35394: len=48 ns/nr=3/2, our ns/nr=2/3, peer ns/nr=3/1
XPRT: tunl 51580: peer ns/nr is 3/2
XPRT: tunl 51580: pkt 1/3 is acked by nr 2
DATA: RX: tunl 51580/35394: rcv 48 bytes from peer 192.168.2.4, packet ns/nr 3/2 type 0
XPRT: tunl 51580: update nr from 3 to 4
AVP: tunl 51580: ICCN message decode of 28 bytes started
AVPDATA: TX_CONNECT_SPEED: value=100000000
AVPDATA: FRAMING_TYPE: type=1
AVPDATA: PROXY_AUTH_TYPE: value=4
PROTO: tunl 51580/35394: ICCN received from peer 28
FSM: LNIC(51580/35394) event ICCN_ACCEPT in state WAITCONNECT
51580/35394: starting UNIX pppd
sess 51580/35394: pppd 10.5.1.1:10.5.1.2 debug kdebug 7 noipdefault sync nodetach local auth noaccomp nopcomp nobsdcomp nodeflate nopredictor1 novj novjccomp noendpoint nomp plugin pppol2tp.so plugin openl2tp.so pppol2tp 17 pppol2tp_lns_mode pppol2tp_tunnel_id 51580 pppol2tp_session_id 35394 pppol2tp_debug_mask 15
sess 51580/35394: spawned pppd pid=9904
FSM: LNIC(51580/35394) state change: WAITCONNECT --> ESTABLISHED
XPRT: RX: tunl 51580/0: len=12 ns/nr=4/2, our ns/nr=2/4, peer ns/nr=3/2
XPRT: tunl 51580: zlb ack received: ns/nr=4/2
XPRT: tunl 51580: peer ns/nr is 4/2
Plugin pppol2tp.so loaded.
Plugin openl2tp.so loaded.
Enabling LCP snooping
using channel 25
Using interface ppp0
Connect: ppp0 <-->
PPPoL2TP options: lnsmode tid 51580 sid 35394 debugmask 15
sent [LCP ConfReq id=0x1 <asyncmap 0x0> <auth eap> <magic 0x99e80135>]
rcvd [LCP ConfNak id=0x1 <auth chap MS-v2>]
sent [LCP ConfReq id=0x2 <asyncmap 0x0> <auth chap MS-v2> <magic 0x99e80135>]
rcvd [LCP ConfAck id=0x2 <asyncmap 0x0> <auth chap MS-v2> <magic 0x99e80135>]
Found option type 02; len 6
Found ACCM of 00000000 (incoming)
Found option type 03; len 5
Found option type 05; len 6
XPRT: tunl 51580: send zlb ack, ns/nr=2/4
rcvd [LCP ConfReq id=0x1 <mru 1400> <magic 0x626b3d6e> <pcomp> <accomp>]
sent [LCP ConfAck id=0x1 <mru 1400> <magic 0x626b3d6e> <pcomp> <accomp>]
Found option type 01; len 4
Found option type 05; len 6
Found option type 07; len 2
Found option type 08; len 2
PPPoL2TP options: lnsmode tid 51580 sid 35394 debugmask 15
sent [LCP EchoReq id=0x0 magic=0x99e80135]
sent [CHAP Challenge id=0x54 <45624355d5aa93822cc511258df0fbea>, name = "linux-5u8g"]
rcvd [LCP EchoRep id=0x0 magic=0x626b3d6e]
rcvd [CHAP Response id=0x54 <b7253dc52baa9b7fb8f4b34fcc03153f0000000000000000a49c1d2c6109af71988b6f30cb6374e58124994e1932e9aa00>, name = "administrator"]
sent [CHAP Success id=0x54 "S=D95B843AD4F3074A3E7CABE254BE1588896C7F29 M=Access granted"]
sent [IPCP ConfReq id=0x1 <addr 10.5.1.1>]
rcvd [CCP ConfReq id=0x2 <mppe +H -M -S -L -D -C>]
sent [CCP ConfReq id=0x1]
sent [CCP ConfRej id=0x2 <mppe +H -M -S -L -D -C>]
rcvd [IPCP ConfReq id=0x3 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-wins 0.0.0.0> <ms-dns2 0.0.0.0> <ms-wins 0.0.0.0>]
sent [IPCP ConfRej id=0x3 <ms-dns1 0.0.0.0> <ms-wins 0.0.0.0> <ms-dns2 0.0.0.0> <ms-wins 0.0.0.0>]
rcvd [IPCP ConfAck id=0x1 <addr 10.5.1.1>]
rcvd [CCP ConfAck id=0x1]
rcvd [CCP TermReq id=0x4"bk=n\000<\37777777715t\000\000\002\37777777734"]
sent [CCP TermAck id=0x4]
rcvd [IPCP ConfReq id=0x5 <addr 0.0.0.0>]
sent [IPCP ConfNak id=0x5 <addr 192.168.2.4>]
rcvd [IPCP ConfReq id=0x6 <addr 192.168.2.4>]
sent [IPCP ConfAck id=0x6 <addr 192.168.2.4>]
local IP address 10.5.1.1
remote IP address 192.168.2.4
FUNC: tunl 51580/35394: using interface ppp0
FUNC: tunl 51580/35394: user is administrator
openl2tp send: sent PPP_UPDOWN_IND, 72 bytes
Script /etc/ppp/ip-up started (pid 9906)
rcvd [IPCP TermReq id=0x7 "bk=n\000<\37777777715t\000\000\0004"]
IPCP terminated by peer (bk=n^@<M-Mt^@^@^@4)
openl2tp send: sent PPP_UPDOWN_IND, 72 bytes
Connect time 0.0 minutes.
Sent 0 bytes, received 0 bytes.
sent [IPCP TermAck id=0x7]
rcvd [LCP TermReq id=0x8 "bk=n\000<\37777777715t\000\000\000\000"]
LCP terminated by peer (bk=n^@<M-Mt^@^@^@^@)
PPPoL2TP options: lnsmode tid 51580 sid 35394 debugmask 15
sent [LCP TermAck id=0x8]
XPRT: RX: tunl 51580/35394: len=38 ns/nr=4/2, our ns/nr=2/4, peer ns/nr=4/2
XPRT: tunl 51580: peer ns/nr is 4/2
DATA: RX: tunl 51580/35394: rcv 38 bytes from peer 192.168.2.4, packet ns/nr 4/2 type 0
XPRT: tunl 51580: update nr from 4 to 5
AVP: tunl 51580: CDN message decode of 18 bytes started
AVPDATA: RESULT_CODE: result=3 error=0 msg=
AVPDATA: SESSION_ID: id=1
PROTO: tunl 51580/35394: CDN received from peer 28
PROTO: session 51580/35394, CDN error 3/0: Call disconnected for administrative reasons
FSM: LNIC(51580/35394) event CDN in state ESTABLISHED
51580/35394: stopping unix pppd pid 9904
51580/35394: cleaning UNIX pppd context
FSM: LNIC(51580/35394) state change: ESTABLISHED --> IDLE
Terminating on signal 15
XPRT: tunl 51580: send zlb ack, ns/nr=2/5
XPRT: RX: tunl 51580/0: len=38 ns/nr=5/2, our ns/nr=2/5, peer ns/nr=4/2
XPRT: tunl 51580: peer ns/nr is 5/2
DATA: RX: tunl 51580/0: rcv 38 bytes from peer 192.168.2.4, packet ns/nr 5/2 type 0
XPRT: tunl 51580: update nr from 5 to 6
AVP: tunl 51580: STOPCCN message decode of 18 bytes started
AVPDATA: TUNNEL_ID: id=28
AVPDATA: RESULT_CODE: result=6 error=0 msg=
PROTO: tunl 51580: STOPCCN received
PROTO: tunl 51580: STOPCCN error 6/0: Requester is being shut down
FSM: CCE(51580) event STOPCCN in state ESTABLISHED
FUNC: tunl 51580 down
FUNC: tunl 51580: starting cleanup timer
FSM: CCE(51580) state change: ESTABLISHED --> CLOSING
tunl 51580: tunnel close acknowledged by peer
XPRT: tunl 51580: send zlb ack, ns/nr=2/6
Connection terminated.
Connect time 0.0 minutes.
Sent 4 bytes, received 0 bytes.
Modem hangup
Waiting for 1 child processes...
script /etc/ppp/ip-up, pid 9906
FUNC: tunl 51580 deleted
FUNC: tunl 51580: deleting context
sending SIGTERM to process 9906
Child process /etc/ppp/ip-up (pid 9906) terminated with signal 15
Script /etc/ppp/ip-down started (pid 9976)

on the client side, i get the following PPP logs:

[616] 06:27:18:142: PPPEMSG_Start recvd, d=, hPort=1,callback=0,mask=810008,IfType=-1
[380] 06:27:18:142: Line up event occurred on port 1
[380] 06:27:18:152: Local identification = MSRAS-0-WINCLIENTMACHIN
[380] 06:27:18:152: PortName: VPN4-1
[380] 06:27:18:152: Starting PPP on link with IfType=0xffffffff,IPIf=0xffffffff,IPXIf=0xffffffff
[380] 06:27:18:152: RasGetBuffer returned 32ceaf0 for SendBuf
[380] 06:27:18:152: FsmInit called for protocol = c021, port = 1
[380] 06:27:18:152: ConfigInfo = 810008
[380] 06:27:18:152: APs available = 42
[380] 06:27:18:152: FsmReset called for protocol = c021, port = 1
[380] 06:27:18:152: Inserting port in bucket # 1
[380] 06:27:18:152: Inserting bundle in bucket # 0
[380] 06:27:18:152: FsmOpen event received for protocol c021 on port 1
[380] 06:27:18:152: FsmThisLayerStarted called for protocol = c021, port = 1
[380] 06:27:18:152: FsmUp event received for protocol c021 on port 1
[380] 06:27:18:152: <PPP packet sent at 11/12/2009 14:27:18:152
[380] 06:27:18:152: <Protocol = LCP, Type = Configure-Req, Length = 0x14, Id = 0x0, Port = 1
[380] 06:27:18:152: <C0 21 01 00 00 12 01 04 05 78 05 06 62 6B 3D 6E |.!.......x..bk=n|
[380] 06:27:18:152: <07 02 08 02 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[380] 06:27:18:152:
[380] 06:27:18:152: InsertInTimerQ called portid=46,Id=0,Protocol=c021,EventType=0,fAuth=0
[380] 06:27:18:152: InsertInTimerQ called portid=46,Id=0,Protocol=0,EventType=3,fAuth=0
[248] 06:27:18:683: Packet received (22 bytes) for hPort 1
[380] 06:27:18:683: >PPP packet received at 11/12/2009 14:27:18:683
[380] 06:27:18:683: >Protocol = LCP, Type = Configure-Req, Length = 0x16, Id = 0x1, Port = 1
[380] 06:27:18:683: >C0 21 01 01 00 14 02 06 00 00 00 00 03 04 C2 27 |.!.............'|
[380] 06:27:18:683: >05 06 99 E8 01 35 00 00 00 00 00 00 00 00 00 00 |.....5..........|
[380] 06:27:18:683:
[380] 06:27:18:683: <PPP packet sent at 11/12/2009 14:27:18:683
[380] 06:27:18:683: <Protocol = LCP, Type = Configure-Nak, Length = 0xb, Id = 0x1, Port = 1
[380] 06:27:18:683: <C0 21 03 01 00 09 03 05 C2 23 81 00 00 00 00 00 |.!.......#......|
[380] 06:27:18:683:
[248] 06:27:18:733: Packet received (23 bytes) for hPort 1
[380] 06:27:18:733: >PPP packet received at 11/12/2009 14:27:18:733
[380] 06:27:18:733: >Protocol = LCP, Type = Configure-Req, Length = 0x17, Id = 0x2, Port = 1
[380] 06:27:18:733: >C0 21 01 02 00 15 02 06 00 00 00 00 03 05 C2 23 |.!.............#|
[380] 06:27:18:733: >81 05 06 99 E8 01 35 00 00 00 00 00 00 00 00 00 |......5.........|
[380] 06:27:18:733:
[380] 06:27:18:733: <PPP packet sent at 11/12/2009 14:27:18:733
[380] 06:27:18:733: <Protocol = LCP, Type = Configure-Ack, Length = 0x17, Id = 0x2, Port = 1
[380] 06:27:18:733: <C0 21 02 02 00 15 02 06 00 00 00 00 03 05 C2 23 |.!.............#|
[380] 06:27:18:733: <81 05 06 99 E8 01 35 00 00 00 00 00 00 00 00 00 |......5.........|
[380] 06:27:18:733:
[380] 06:27:20:155: Recv timeout event received for portid=46,Id=0,Protocol=c021,fAuth=0
[380] 06:27:20:155: <PPP packet sent at 11/12/2009 14:27:20:155
[380] 06:27:20:155: <Protocol = LCP, Type = Configure-Req, Length = 0x14, Id = 0x1, Port = 1
[380] 06:27:20:155: <C0 21 01 01 00 12 01 04 05 78 05 06 62 6B 3D 6E |.!.......x..bk=n|
[380] 06:27:20:155: <07 02 08 02 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[380] 06:27:20:155:
[380] 06:27:20:155: InsertInTimerQ called portid=46,Id=1,Protocol=c021,EventType=0,fAuth=0
[248] 06:27:20:155: Packet received (20 bytes) for hPort 1
[380] 06:27:20:155: >PPP packet received at 11/12/2009 14:27:20:155
[380] 06:27:20:155: >Protocol = LCP, Type = Configure-Ack, Length = 0x14, Id = 0x1, Port = 1
[380] 06:27:20:155: >C0 21 02 01 00 12 01 04 05 78 05 06 62 6B 3D 6E |.!.......x..bk=n|
[380] 06:27:20:155: >07 02 08 02 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[380] 06:27:20:155:
[380] 06:27:20:155: RemoveFromTimerQ called portid=46,Id=1,Protocol=c021,EventType=0,fAuth=0
[380] 06:27:20:155: FsmThisLayerUp called for protocol = c021, port = 1
[380] 06:27:20:155: LCP Local Options-------------
[380] 06:27:20:155: MRU=1400,ACCM=-1,Auth=0,MagicNumber=1651195246,PFC=ON,ACFC=ON
[380] 06:27:20:155: Recv Framing = PPP,SSHF=OFF,MRRU=1500,LinkDiscrim=0,BAP=OFF
[380] 06:27:20:155: LCP Remote Options-------------
[380] 06:27:20:155: MRU=1500,ACCM=0,Auth=c223,MagicNumber=-1712848587,PFC=OFF,ACFC=OFF
[380] 06:27:20:155: Send Framing = PPP,SSHF=OFF,MRRU=1500,LinkDiscrim=0
[380] 06:27:20:155: LCP Configured successfully
[380] 06:27:20:155: Authenticating phase started
[380] 06:27:20:155: Calling APWork in APStart
[248] 06:27:20:175: Packet received (10 bytes) for hPort 1
[380] 06:27:20:175: >PPP packet received at 11/12/2009 14:27:20:175
[380] 06:27:20:175: >Protocol = LCP, Type = Echo-Request, Length = 0xa, Id = 0x0, Port = 1
[380] 06:27:20:175: >C0 21 09 00 00 08 99 E8 01 35 00 00 00 00 00 00 |.!.......5......|
[380] 06:27:20:175:
[380] 06:27:20:175: <PPP packet sent at 11/12/2009 14:27:20:175
[380] 06:27:20:175: <Protocol = LCP, Type = Echo-Reply, Length = 0xa, Id = 0x0, Port = 1
[380] 06:27:20:175: <C0 21 0A 00 00 08 62 6B 3D 6E 00 00 00 00 00 00 |.!....bk=n......|
[380] 06:27:20:175:
[248] 06:27:20:175: Packet received (33 bytes) for hPort 1
[380] 06:27:20:175: >PPP packet received at 11/12/2009 14:27:20:175
[380] 06:27:20:175: >Protocol = CHAP, Type = Protocol specific, Length = 0x21, Id = 0x54, Port = 1
[380] 06:27:20:175: >C2 23 01 54 00 1F 10 45 62 43 55 D5 AA 93 82 2C |.#.T...EbCU....,|
[380] 06:27:20:175: >C5 11 25 8D F0 FB EA 6C 69 6E 75 78 2D 35 75 38 |..%....linux-5u8|
[380] 06:27:20:175: >67 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |g...............|
[380] 06:27:20:175:
[380] 06:27:20:185: <PPP packet sent at 11/12/2009 14:27:20:185
[380] 06:27:20:185: <Protocol = CHAP, Type = Protocol specific, Length = 0x45, Id = 0x54, Port = 1
[380] 06:27:20:185: <C2 23 02 54 00 43 31 B7 25 3D C5 2B AA 9B 7F B8 |.#.T.C1.%=.+...|
[380] 06:27:20:185: <F4 B3 4F CC 03 15 3F 00 00 00 00 00 00 00 00 A4 |..O...?.........|
[380] 06:27:20:185: <9C 1D 2C 61 09 AF 71 98 8B 6F 30 CB 63 74 E5 81 |..,a..q..o0.ct..|
[380] 06:27:20:185: <24 99 4E 19 32 E9 AA 00 61 64 6D 69 6E 69 73 74 |$.N.2...administ|
[380] 06:27:20:185: <72 61 74 6F 72 00 00 00 00 00 00 00 00 00 00 00 |rator...........|
[380] 06:27:20:185:
[380] 06:27:20:185: InsertInTimerQ called portid=46,Id=84,Protocol=c223,EventType=0,fAuth=0
[248] 06:27:20:235: Packet received (65 bytes) for hPort 1
[380] 06:27:20:235: >PPP packet received at 11/12/2009 14:27:20:235
[380] 06:27:20:235: >Protocol = CHAP, Type = Protocol specific, Length = 0x41, Id = 0x54, Port = 1
[380] 06:27:20:235: >C2 23 03 54 00 3F 53 3D 44 39 35 42 38 34 33 41 |.#.T.?S=D95B843A|
[380] 06:27:20:235: >44 34 46 33 30 37 34 41 33 45 37 43 41 42 45 32 |D4F3074A3E7CABE2|
[380] 06:27:20:235: >35 34 42 45 31 35 38 38 38 39 36 43 37 46 32 39 |54BE1588896C7F29|
[380] 06:27:20:235: >20 4D 3D 41 63 63 65 73 73 20 67 72 61 6E 74 65 | M=Access grante|
[380] 06:27:20:235: >64 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |d...............|
[380] 06:27:20:235:
[380] 06:27:20:235: RemoveFromTimerQ called portid=46,Id=84,Protocol=c223,EventType=0,fAuth=0
[380] 06:27:20:235: MS-CHAP-MPPE-Keys set
[380] 06:27:20:235: Checking encryption. Policy=0x0,Types=0x0,Mask=0x4
[380] 06:27:20:235: FsmThisLayerUp called for protocol = c223, port = 1
[380] 06:27:20:235: NotifyCaller(hPort=1, dwMsgId=17)
[380] 06:27:20:235: NotifyCaller(hPort=1, dwMsgId=3)
[380] 06:27:20:235: Will not initialize CP 8029
[380] 06:27:20:235: Will not initialize CP 802b
[380] 06:27:20:235: FsmInit called for protocol = 80fd, port = 1
[380] 06:27:20:235: FsmReset called for protocol = 80fd, port = 1
[380] 06:27:20:235: FsmInit called for protocol = 8021, port = 1
[380] 06:27:20:245: FsmReset called for protocol = 8021, port = 1
[380] 06:27:20:245: FsmOpen event received for protocol 80fd on port 1
[380] 06:27:20:245: FsmThisLayerStarted called for protocol = 80fd, port = 1
[380] 06:27:20:245: FsmUp event received for protocol 80fd on port 1
[380] 06:27:20:245: <PPP packet sent at 11/12/2009 14:27:20:245
[380] 06:27:20:245: <Protocol = CCP, Type = Configure-Req, Length = 0xc, Id = 0x2, Port = 1
[380] 06:27:20:245: <80 FD 01 02 00 0A 12 06 01 00 00 00 00 00 00 00 |................|
[380] 06:27:20:245:
[380] 06:27:20:245: InsertInTimerQ called portid=46,Id=2,Protocol=80fd,EventType=0,fAuth=0
[380] 06:27:20:245: FsmOpen event received for protocol 8021 on port 1
[380] 06:27:20:245: FsmThisLayerStarted called for protocol = 8021, port = 1
[380] 06:27:20:245: FsmUp event received for protocol 8021 on port 1
[380] 06:27:20:245: <PPP packet sent at 11/12/2009 14:27:20:245
[380] 06:27:20:245: <Protocol = IPCP, Type = Configure-Req, Length = 0x24, Id = 0x3, Port = 1
[380] 06:27:20:245: <80 21 01 03 00 22 03 06 00 00 00 00 81 06 00 00 |.!..."..........|
[380] 06:27:20:245: <00 00 82 06 00 00 00 00 83 06 00 00 00 00 84 06 |................|
[380] 06:27:20:245: <00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[380] 06:27:20:245:
[380] 06:27:20:245: InsertInTimerQ called portid=46,Id=3,Protocol=8021,EventType=0,fAuth=0
[248] 06:27:20:265: Packet received (12 bytes) for hPort 1
[380] 06:27:20:265: >PPP packet received at 11/12/2009 14:27:20:265
[380] 06:27:20:265: >Protocol = IPCP, Type = Configure-Req, Length = 0xc, Id = 0x1, Port = 1
[380] 06:27:20:265: >80 21 01 01 00 0A 03 06 0A 05 01 01 00 00 00 00 |.!..............|
[380] 06:27:20:265:
[380] 06:27:20:265: <PPP packet sent at 11/12/2009 14:27:20:265
[380] 06:27:20:265: <Protocol = IPCP, Type = Configure-Ack, Length = 0xc, Id = 0x1, Port = 1
[380] 06:27:20:265: <80 21 02 01 00 0A 03 06 0A 05 01 01 00 00 00 00 |.!..............|
[380] 06:27:20:265:
[248] 06:27:20:295: Packet received (6 bytes) for hPort 1
[380] 06:27:20:295: >PPP packet received at 11/12/2009 14:27:20:295
[380] 06:27:20:295: >Protocol = CCP, Type = Configure-Req, Length = 0x6, Id = 0x1, Port = 1
[380] 06:27:20:295: >80 FD 01 01 00 04 00 00 00 00 00 00 00 00 00 00 |................|
[380] 06:27:20:295:
[380] 06:27:20:295: <PPP packet sent at 11/12/2009 14:27:20:295
[380] 06:27:20:295: <Protocol = CCP, Type = Configure-Ack, Length = 0x6, Id = 0x1, Port = 1
[380] 06:27:20:295: <80 FD 02 01 00 04 00 00 00 00 00 00 00 00 00 00 |................|
[380] 06:27:20:295:
[248] 06:27:20:325: Packet received (12 bytes) for hPort 1
[380] 06:27:20:325: >PPP packet received at 11/12/2009 14:27:20:325
[380] 06:27:20:325: >Protocol = CCP, Type = Configure-Reject, Length = 0xc, Id = 0x2, Port = 1
[380] 06:27:20:325: >80 FD 04 02 00 0A 12 06 01 00 00 00 00 00 00 00 |................|
[380] 06:27:20:325:
[380] 06:27:20:325: The control protocol for 80fd on port 1 returned error 732
[380] 06:27:20:325: FsmClose event received for protocol 80fd on port 1
[380] 06:27:20:325: RemoveFromTimerQ called portid=46,Id=2,Protocol=80fd,EventType=0,fAuth=0
[380] 06:27:20:325: <PPP packet sent at 11/12/2009 14:27:20:325
[380] 06:27:20:325: <Protocol = CCP, Type = Terminate-Req, Length = 0x12, Id = 0x4, Port = 1
[380] 06:27:20:325: <80 FD 05 04 00 10 62 6B 3D 6E 00 3C CD 74 00 00 |......bk=n.<.t..|
[380] 06:27:20:325: <02 DC 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[380] 06:27:20:325:
[380] 06:27:20:325: InsertInTimerQ called portid=46,Id=4,Protocol=80fd,EventType=0,fAuth=0
[248] 06:27:20:355: Packet received (30 bytes) for hPort 1
[380] 06:27:20:355: >PPP packet received at 11/12/2009 14:27:20:355
[380] 06:27:20:355: >Protocol = IPCP, Type = Configure-Reject, Length = 0x1e, Id = 0x3, Port = 1
[380] 06:27:20:355: >80 21 04 03 00 1C 81 06 00 00 00 00 82 06 00 00 |.!..............|
[380] 06:27:20:355: >00 00 83 06 00 00 00 00 84 06 00 00 00 00 00 00 |................|
[380] 06:27:20:355:
[380] 06:27:20:355: RemoveFromTimerQ called portid=46,Id=3,Protocol=8021,EventType=0,fAuth=0
[380] 06:27:20:355: <PPP packet sent at 11/12/2009 14:27:20:355
[380] 06:27:20:355: <Protocol = IPCP, Type = Configure-Req, Length = 0xc, Id = 0x5, Port = 1
[380] 06:27:20:355: <80 21 01 05 00 0A 03 06 00 00 00 00 00 00 00 00 |.!..............|
[380] 06:27:20:355:
[380] 06:27:20:365: InsertInTimerQ called portid=46,Id=5,Protocol=8021,EventType=0,fAuth=0
[248] 06:27:20:395: Packet received (6 bytes) for hPort 1
[380] 06:27:20:395: >PPP packet received at 11/12/2009 14:27:20:395
[380] 06:27:20:395: >Protocol = CCP, Type = Terminate-Ack, Length = 0x6, Id = 0x4, Port = 1
[380] 06:27:20:395: >80 FD 06 04 00 04 00 00 00 00 00 00 00 00 00 00 |................|
[380] 06:27:20:395:
[380] 06:27:20:395: RemoveFromTimerQ called portid=46,Id=4,Protocol=80fd,EventType=0,fAuth=0
[380] 06:27:20:395: FsmThisLayerFinished called for protocol = 80fd, port = 1
[248] 06:27:20:395: Packet received (12 bytes) for hPort 1
[380] 06:27:20:395: >PPP packet received at 11/12/2009 14:27:20:395
[380] 06:27:20:395: >Protocol = IPCP, Type = Configure-Nak, Length = 0xc, Id = 0x5, Port = 1
[380] 06:27:20:395: >80 21 03 05 00 0A 03 06 C0 A8 02 04 00 00 00 00 |.!..............|
[380] 06:27:20:395:
[380] 06:27:20:395: RemoveFromTimerQ called portid=46,Id=5,Protocol=8021,EventType=0,fAuth=0
[380] 06:27:20:395: <PPP packet sent at 11/12/2009 14:27:20:395
[380] 06:27:20:395: <Protocol = IPCP, Type = Configure-Req, Length = 0xc, Id = 0x6, Port = 1
[380] 06:27:20:395: <80 21 01 06 00 0A 03 06 C0 A8 02 04 00 00 00 00 |.!..............|
[380] 06:27:20:395:
[380] 06:27:20:395: InsertInTimerQ called portid=46,Id=6,Protocol=8021,EventType=0,fAuth=0
[248] 06:27:20:435: Packet received (12 bytes) for hPort 1
[380] 06:27:20:435: >PPP packet received at 11/12/2009 14:27:20:435
[380] 06:27:20:435: >Protocol = IPCP, Type = Configure-Ack, Length = 0xc, Id = 0x6, Port = 1
[380] 06:27:20:435: >80 21 02 06 00 0A 03 06 C0 A8 02 04 00 00 00 00 |.!..............|
[380] 06:27:20:435:
[380] 06:27:20:435: RemoveFromTimerQ called portid=46,Id=6,Protocol=8021,EventType=0,fAuth=0
[380] 06:27:20:435: FsmThisLayerUp called for protocol = 8021, port = 1
[380] 06:27:20:465: Notifying IPCP of projection notification
[380] 06:27:20:465: RasIPCPProjectionNotification returned 52
[380] 06:27:20:465: FsmClose event received for protocol 8021 on port 1
[380] 06:27:20:465: RemoveFromTimerQ called portid=46,Id=6,Protocol=8021,EventType=0,fAuth=0
[380] 06:27:20:465: FsmThisLayerDown called for protocol = 8021, port = 1
[380] 06:27:20:465: <PPP packet sent at 11/12/2009 14:27:20:465
[380] 06:27:20:465: <Protocol = IPCP, Type = Terminate-Req, Length = 0x12, Id = 0x7, Port = 1
[380] 06:27:20:465: <80 21 05 07 00 10 62 6B 3D 6E 00 3C CD 74 00 00 |.!....bk=n.<.t..|
[380] 06:27:20:465: <00 34 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |.4..............|
[380] 06:27:20:465:
[380] 06:27:20:465: InsertInTimerQ called portid=46,Id=7,Protocol=8021,EventType=0,fAuth=0
[248] 06:27:20:615: Packet received (6 bytes) for hPort 1
[380] 06:27:20:615: >PPP packet received at 11/12/2009 14:27:20:615
[380] 06:27:20:615: >Protocol = IPCP, Type = Terminate-Ack, Length = 0x6, Id = 0x7, Port = 1
[380] 06:27:20:615: >80 21 06 07 00 04 00 00 00 00 00 00 00 00 00 00 |.!..............|
[380] 06:27:20:615:
[380] 06:27:20:615: RemoveFromTimerQ called portid=46,Id=7,Protocol=8021,EventType=0,fAuth=0
[380] 06:27:20:615: FsmThisLayerFinished called for protocol = 8021, port = 1
[380] 06:27:20:615: Notifying IPCP of projection notification
[380] 06:27:20:615: RemoveFromTimerQ called portid=46,Id=0,Protocol=0,EventType=3,fAuth=0
[380] 06:27:20:615: NotifyCaller(hPort=1, dwMsgId=4)
[380] 06:27:20:615: NotifyCaller(hPort=1, dwMsgId=0)
[380] 06:27:20:615: Inserting autodisconnect in timer q for port=1, sec=-1
[380] 06:27:20:625: RemoveFromTimerQ called portid=46,Id=0,Protocol=0,EventType=1,fAuth=0
[380] 06:27:20:625: InsertInTimerQ called portid=46,Id=0,Protocol=0,EventType=1,fAuth=0
[616] 06:27:20:635: PppStop

[616] 06:27:20:635: PPPEMSG_Stop recvd

[380] 06:27:20:635: FsmClose event received for protocol c021 on port 1
[380] 06:27:20:635: RemoveFromTimerQ called portid=46,Id=1,Protocol=c021,EventType=0,fAuth=0
[380] 06:27:20:635: FsmThisLayerDown called for protocol = c021, port = 1
[380] 06:27:20:635: FsmDown event received for protocol 80fd on port 1
[380] 06:27:20:635: RemoveFromTimerQ called portid=46,Id=4,Protocol=80fd,EventType=0,fAuth=0
[380] 06:27:20:635: FsmReset called for protocol = 80fd, port = 1
[380] 06:27:20:635: FsmDown event received for protocol 8021 on port 1
[380] 06:27:20:635: RemoveFromTimerQ called portid=46,Id=7,Protocol=8021,EventType=0,fAuth=0
[380] 06:27:20:635: FsmReset called for protocol = 8021, port = 1
[380] 06:27:20:635: RemoveFromTimerQ called portid=46,Id=84,Protocol=c223,EventType=0,fAuth=0
[380] 06:27:20:635: RemoveFromTimerQ called portid=46,Id=0,Protocol=c029,EventType=0,fAuth=0
[380] 06:27:20:635: <PPP packet sent at 11/12/2009 14:27:20:635
[380] 06:27:20:635: <Protocol = LCP, Type = Terminate-Req, Length = 0x12, Id = 0x8, Port = 1
[380] 06:27:20:635: <C0 21 05 08 00 10 62 6B 3D 6E 00 3C CD 74 00 00 |.!....bk=n.<.t..|
[380] 06:27:20:635: <00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[380] 06:27:20:635:
[380] 06:27:20:635: InsertInTimerQ called portid=46,Id=8,Protocol=c021,EventType=0,fAuth=0
[248] 06:27:20:645: Packet received (6 bytes) for hPort 1
[380] 06:27:20:645: >PPP packet received at 11/12/2009 14:27:20:645
[380] 06:27:20:645: >Protocol = LCP, Type = Terminate-Ack, Length = 0x6, Id = 0x8, Port = 1
[380] 06:27:20:645: >C0 21 06 08 00 04 00 00 00 00 00 00 00 00 00 00 |.!..............|
[380] 06:27:20:645:
[380] 06:27:20:645: RemoveFromTimerQ called portid=46,Id=8,Protocol=c021,EventType=0,fAuth=0
[380] 06:27:20:645: FsmThisLayerFinished called for protocol = c021, port = 1
[380] 06:27:20:645: FsmThisLayerFinished called for protocol = 80fd, port = 1: 0
[380] 06:27:20:645: FsmThisLayerFinished called for protocol = 8021, port = 1: 0
[380] 06:27:20:645: NotifyCaller(hPort=1, dwMsgId=10)
[248] 06:27:22:047: PPPEMSG_LineDown recvd, hPort=1

[380] 06:27:22:047: Line down event occurred on port 1
[380] 06:27:22:047: FsmDown event received for protocol c021 on port 1
[380] 06:27:22:047: RemoveFromTimerQ called portid=46,Id=8,Protocol=c021,EventType=0,fAuth=0
[380] 06:27:22:047: FsmReset called for protocol = c021, port = 1
[380] 06:27:22:047: RemoveFromTimerQ called portid=46,Id=0,Protocol=0,EventType=3,fAuth=0
[380] 06:27:22:047: RemoveFromTimerQ called portid=46,Id=0,Protocol=0,EventType=7,fAuth=0
[380] 06:27:22:047: RemoveFromTimerQ called portid=46,Id=0,Protocol=0,EventType=2,fAuth=0
[380] 06:27:22:047: RemoveFromTimerQ called portid=46,Id=0,Protocol=0,EventType=1,fAuth=0
[380] 06:27:22:047: RemoveFromTimerQ called portid=46,Id=0,Protocol=c029,EventType=0,fAuth=0
[380] 06:27:22:047: LcpEnd
[380] 06:27:22:047: Post line down event occurred on port 1
[380] 06:27:22:047: NotifyCaller(hPort=1, dwMsgId=23)


As far as I understood from the Wireshark's captured packets, the IPSec part is working properly and the authentication is also performesd successfully. But it seems that the Compression Control Protocol is the cause of the problem.
Unfortunately, I don't have any idea of how to fix this problem. I'd be glad if anybody could give me some advice.
Thanks,
Marjan


Top
 Profile  
 
 Post subject: Re: Problem in establishing al L2TP tunnel between a linux serv
PostPosted: Mon Nov 16, 2009 7:34 pm 
Site Admin

Joined: Sun Jul 27, 2008 1:39 pm
Posts: 122
marjan wrote:
I'm trying to establish an L2TP/IPSec tunnel between a suse linux server and a windows XP client. I'v installed openL2TP 1.6 on the server side. The problem is that before the tunnel is established, it is disconnected by the peer.


Hi, it looks like the IPSec connection is fine as the L2TP session comes up and PPP gets a long way through the procedure of negotiating with the peer. IP addresses are assigned, but the connection seems to be then be dropped by XP. See the following in the XP logs.

[380] 06:27:20:435: FsmThisLayerUp called for protocol = 8021, port = 1
[380] 06:27:20:465: Notifying IPCP of projection notification
[380] 06:27:20:465: RasIPCPProjectionNotification returned 52
[380] 06:27:20:465: FsmClose event received for protocol 8021 on port 1
[380] 06:27:20:465: RemoveFromTimerQ called portid=46,Id=6,Protocol=8021,EventType=0,fAuth=0
[380] 06:27:20:465: FsmThisLayerDown called for protocol = 8021, port = 1

What is the significance of "RasIPCPProjectionNotification" returning 52? Is the IP address assigned for the connection one that XP's policies allow? Sorry, I don't know anything about debugging problems on XP. Everything seems ok from the server side. XP drops the session and then the tunnel soon after the connection comes up.


Top
 Profile  
 
 Post subject: Re: Problem in establishing al L2TP tunnel between a linux serv
PostPosted: Mon Nov 16, 2009 10:09 pm 

Joined: Fri Nov 13, 2009 9:25 pm
Posts: 4
Hi,
Thanks a lot for your reply. I thought there was no need to define any special policies for the IP addresses in the client side, or I'm wrong? But I defined the same encryption and authentication algorithms in both sides. As far as I understood from the XP logs, everything is fine until the appearance of the following lines:


[380] 06:27:20:325: >Protocol = CCP, Type = Configure-Reject, Length = 0xc, Id = 0x2, Port = 1
[380] 06:27:20:325: >80 FD 04 02 00 0A 12 06 01 00 00 00 00 00 00 00 |................|
[380] 06:27:20:325:
[380] 06:27:20:325: The control protocol for 80fd on port 1 returned error 732
[380] 06:27:20:325: FsmClose event received for protocol 80fd on port 1

As I searched the Web, I noticed that 80fd relates to the Compression Control Protocol. So the error has something to do with Compression mechanisms. But as it can be seen from the following Linux logs, the compression mechanisms seem to be off in the Linux side, and I've also turned off "Enable Software Encryption" in the XP side.

sess 51580/35394: pppd 10.5.1.1:10.5.1.2 debug kdebug 7 noipdefault sync nodetach local auth noaccomp nopcomp nobsdcomp nodeflate nopredictor1 novj novjccomp noendpoint nomp plugin pppol2tp.so plugin openl2tp.so pppol2tp 17 pppol2tp_lns_mode pppol2tp_tunnel_id 51580 pppol2tp_session_id 35394 pppol2tp_debug_mask 15
sess 51580/35394: spawned pppd pid=9904

I don't have any idea on how to tell PPP to ignore compression. Any help is highly appreciated.

Thanks in advance,
Marjan


Top
 Profile  
 
 Post subject: Re: Problem in establishing al L2TP tunnel between a linux serv
PostPosted: Tue Nov 17, 2009 9:23 am 
Site Admin

Joined: Sun Jul 27, 2008 1:39 pm
Posts: 122
marjan wrote:
Hi,
Thanks a lot for your reply. I thought there was no need to define any special policies for the IP addresses in the client side, or I'm wrong? But I defined the same encryption and authentication algorithms in both sides. As far as I understood from the XP logs, everything is fine until the appearance of the following lines:


[380] 06:27:20:325: >Protocol = CCP, Type = Configure-Reject, Length = 0xc, Id = 0x2, Port = 1
[380] 06:27:20:325: >80 FD 04 02 00 0A 12 06 01 00 00 00 00 00 00 00 |................|
[380] 06:27:20:325:
[380] 06:27:20:325: The control protocol for 80fd on port 1 returned error 732
[380] 06:27:20:325: FsmClose event received for protocol 80fd on port 1

As I searched the Web, I noticed that 80fd relates to the Compression Control Protocol. So the error has something to do with Compression mechanisms. But as it can be seen from the following Linux logs, the compression mechanisms seem to be off in the Linux side, and I've also turned off "Enable Software Encryption" in the XP side.

sess 51580/35394: pppd 10.5.1.1:10.5.1.2 debug kdebug 7 noipdefault sync nodetach local auth noaccomp nopcomp nobsdcomp nodeflate nopredictor1 novj novjccomp noendpoint nomp plugin pppol2tp.so plugin openl2tp.so pppol2tp 17 pppol2tp_lns_mode pppol2tp_tunnel_id 51580 pppol2tp_session_id 35394 pppol2tp_debug_mask 15
sess 51580/35394: spawned pppd pid=9904

I don't have any idea on how to tell PPP to ignore compression. Any help is highly appreciated.

Thanks in advance,
Marjan

Try adding "noccp" to your /etc/ppp/options.

This option will disable CCP altogether. There isn't a parameter in the ppp profile to set noccp so you'll need to edit /etc/ppp/options for now.


Top
 Profile  
 
 Post subject: Re: Problem in establishing al L2TP tunnel between a linux serv
PostPosted: Tue Nov 17, 2009 12:13 pm 

Joined: Fri Nov 13, 2009 9:25 pm
Posts: 4
Thanks a lot. I will check it on and let you know if it works.


Top
 Profile  
 
 Post subject: Re: Problem in establishing al L2TP tunnel between a linux serv
PostPosted: Mon Nov 23, 2009 1:38 pm 

Joined: Fri Nov 13, 2009 9:25 pm
Posts: 4
Hi,
I added noccp in /etc/ppp/options. Window's ppp logs has changed, But it seems Windows has still some problems in understanding that Control Connection Protocol(80fd) is not needed! Any ideas? Is there any special tricks in establishing a tunnel betwwn a Linux server and a windows client??? Thanks in advance.

The followings are Windows PPP logs:

[3136] 07:21:19:847: PPPEMSG_Start recvd, d=, hPort=1,callback=0,mask=810208,IfType=-1
[1312] 07:21:19:847: Line up event occurred on port 1
[1312] 07:21:19:847: Local identification = MSRAS-0-WINCLIENTMACHIN
[1312] 07:21:19:847: PortName: VPN4-1
[1312] 07:21:19:847: Starting PPP on link with IfType=0xffffffff,IPIf=0xffffffff,IPXIf=0xffffffff
[1312] 07:21:19:847: RasGetBuffer returned 3410918 for SendBuf
[1312] 07:21:19:847: FsmInit called for protocol = c021, port = 1
[1312] 07:21:19:847: ConfigInfo = 810208
[1312] 07:21:19:847: APs available = 42
[1312] 07:21:19:847: FsmReset called for protocol = c021, port = 1
[1312] 07:21:19:847: Inserting port in bucket # 1
[1312] 07:21:19:847: Inserting bundle in bucket # 3
[1312] 07:21:19:847: FsmOpen event received for protocol c021 on port 1
[1312] 07:21:19:847: FsmThisLayerStarted called for protocol = c021, port = 1
[1312] 07:21:19:847: FsmUp event received for protocol c021 on port 1
[1312] 07:21:19:847: <PPP packet sent at 11/23/2009 15:21:19:847
[1312] 07:21:19:847: <Protocol = LCP, Type = Configure-Req, Length = 0x17, Id = 0x0, Port = 1
[1312] 07:21:19:847: <C0 21 01 00 00 15 01 04 05 78 05 06 6A 3A 47 84 |.!.......x..j:G.|
[1312] 07:21:19:847: <07 02 08 02 0D 03 06 00 00 00 00 00 00 00 00 00 |................|
[1312] 07:21:19:847:
[1312] 07:21:19:847: InsertInTimerQ called portid=4,Id=0,Protocol=c021,EventType=0,fAuth=0
[1312] 07:21:19:847: InsertInTimerQ called portid=4,Id=0,Protocol=0,EventType=3,fAuth=0
[1056] 07:21:20:348: Packet received (22 bytes) for hPort 1
[1312] 07:21:20:348: >PPP packet received at 11/23/2009 15:21:20:348
[1312] 07:21:20:348: >Protocol = LCP, Type = Configure-Req, Length = 0x16, Id = 0x1, Port = 1
[1312] 07:21:20:348: >C0 21 01 01 00 14 02 06 00 00 00 00 03 04 C2 27 |.!.............'|
[1312] 07:21:20:348: >05 06 54 A9 F1 61 00 00 00 00 00 00 00 00 00 00 |..T..a..........|
[1312] 07:21:20:348:
[1312] 07:21:20:348: <PPP packet sent at 11/23/2009 15:21:20:348
[1312] 07:21:20:348: <Protocol = LCP, Type = Configure-Nak, Length = 0xb, Id = 0x1, Port = 1
[1312] 07:21:20:348: <C0 21 03 01 00 09 03 05 C2 23 81 00 00 00 00 00 |.!.......#......|
[1312] 07:21:20:348:
[1056] 07:21:20:378: Packet received (23 bytes) for hPort 1
[1312] 07:21:20:378: >PPP packet received at 11/23/2009 15:21:20:378
[1312] 07:21:20:378: >Protocol = LCP, Type = Configure-Req, Length = 0x17, Id = 0x2, Port = 1
[1312] 07:21:20:378: >C0 21 01 02 00 15 02 06 00 00 00 00 03 05 C2 23 |.!.............#|
[1312] 07:21:20:378: >81 05 06 54 A9 F1 61 00 00 00 00 00 00 00 00 00 |...T..a.........|
[1312] 07:21:20:378:
[1312] 07:21:20:378: <PPP packet sent at 11/23/2009 15:21:20:378
[1312] 07:21:20:378: <Protocol = LCP, Type = Configure-Ack, Length = 0x17, Id = 0x2, Port = 1
[1312] 07:21:20:378: <C0 21 02 02 00 15 02 06 00 00 00 00 03 05 C2 23 |.!.............#|
[1312] 07:21:20:378: <81 05 06 54 A9 F1 61 00 00 00 00 00 00 00 00 00 |...T..a.........|
[1312] 07:21:20:378:
[1312] 07:21:21:850: Recv timeout event received for portid=4,Id=0,Protocol=c021,fAuth=0
[1312] 07:21:21:850: <PPP packet sent at 11/23/2009 15:21:21:850
[1312] 07:21:21:850: <Protocol = LCP, Type = Configure-Req, Length = 0x17, Id = 0x1, Port = 1
[1312] 07:21:21:850: <C0 21 01 01 00 15 01 04 05 78 05 06 6A 3A 47 84 |.!.......x..j:G.|
[1312] 07:21:21:850: <07 02 08 02 0D 03 06 00 00 00 00 00 00 00 00 00 |................|
[1312] 07:21:21:850:
[1312] 07:21:21:850: InsertInTimerQ called portid=4,Id=1,Protocol=c021,EventType=0,fAuth=0
[1056] 07:21:21:850: Packet received (9 bytes) for hPort 1
[1312] 07:21:21:850: >PPP packet received at 11/23/2009 15:21:21:850
[1312] 07:21:21:850: >Protocol = LCP, Type = Configure-Reject, Length = 0x9, Id = 0x1, Port = 1
[1312] 07:21:21:850: >C0 21 04 01 00 07 0D 03 06 00 00 00 00 00 00 00 |.!..............|
[1312] 07:21:21:850:
[1312] 07:21:21:850: RemoveFromTimerQ called portid=4,Id=1,Protocol=c021,EventType=0,fAuth=0
[1312] 07:21:21:850: <PPP packet sent at 11/23/2009 15:21:21:850
[1312] 07:21:21:850: <Protocol = LCP, Type = Configure-Req, Length = 0x14, Id = 0x2, Port = 1
[1312] 07:21:21:850: <C0 21 01 02 00 12 01 04 05 78 05 06 6A 3A 47 84 |.!.......x..j:G.|
[1312] 07:21:21:850: <07 02 08 02 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[1312] 07:21:21:850:
[1312] 07:21:21:850: InsertInTimerQ called portid=4,Id=2,Protocol=c021,EventType=0,fAuth=0
[1056] 07:21:21:860: Packet received (20 bytes) for hPort 1
[1312] 07:21:21:860: >PPP packet received at 11/23/2009 15:21:21:860
[1312] 07:21:21:860: >Protocol = LCP, Type = Configure-Ack, Length = 0x14, Id = 0x2, Port = 1
[1312] 07:21:21:860: >C0 21 02 02 00 12 01 04 05 78 05 06 6A 3A 47 84 |.!.......x..j:G.|
[1312] 07:21:21:860: >07 02 08 02 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[1312] 07:21:21:860:
[1312] 07:21:21:860: RemoveFromTimerQ called portid=4,Id=2,Protocol=c021,EventType=0,fAuth=0
[1312] 07:21:21:860: FsmThisLayerUp called for protocol = c021, port = 1
[1312] 07:21:21:860: LCP Local Options-------------
[1312] 07:21:21:860: MRU=1400,ACCM=-1,Auth=0,MagicNumber=1782204292,PFC=ON,ACFC=ON
[1312] 07:21:21:860: Recv Framing = PPP,SSHF=OFF,MRRU=1500,LinkDiscrim=0,BAP=OFF
[1312] 07:21:21:860: LCP Remote Options-------------
[1312] 07:21:21:860: MRU=1500,ACCM=0,Auth=c223,MagicNumber=1420423521,PFC=OFF,ACFC=OFF
[1312] 07:21:21:860: Send Framing = PPP,SSHF=OFF,MRRU=1500,LinkDiscrim=0
[1312] 07:21:21:860: LCP Configured successfully
[1312] 07:21:21:860: <PPP packet sent at 11/23/2009 15:21:21:860
[1312] 07:21:21:860: <Protocol = LCP, Type = Identification, Length = 0x14, Id = 0x3, Port = 1
[1312] 07:21:21:860: <C0 21 0C 03 00 12 6A 3A 47 84 4D 53 52 41 53 56 |.!....j:G.MSRASV|
[1312] 07:21:21:860: <35 2E 31 30 00 00 00 00 00 00 00 00 00 00 00 00 |5.10............|
[1312] 07:21:21:860:
[1312] 07:21:21:860: <PPP packet sent at 11/23/2009 15:21:21:860
[1312] 07:21:21:860: <Protocol = LCP, Type = Identification, Length = 0x21, Id = 0x4, Port = 1
[1312] 07:21:21:860: <C0 21 0C 04 00 1F 6A 3A 47 84 4D 53 52 41 53 2D |.!....j:G.MSRAS-|
[1312] 07:21:21:860: <30 2D 57 49 4E 43 4C 49 45 4E 54 4D 41 43 48 49 |0-WINCLIENTMACHI|
[1312] 07:21:21:860: <4E 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |N...............|
[1312] 07:21:21:860:
[1312] 07:21:21:860: Authenticating phase started
[1312] 07:21:21:860: Calling APWork in APStart
[1056] 07:21:21:880: Packet received (10 bytes) for hPort 1
[1312] 07:21:21:880: >PPP packet received at 11/23/2009 15:21:21:880
[1312] 07:21:21:880: >Protocol = LCP, Type = Echo-Request, Length = 0xa, Id = 0x0, Port = 1
[1312] 07:21:21:880: >C0 21 09 00 00 08 54 A9 F1 61 00 00 00 00 00 00 |.!....T..a......|
[1312] 07:21:21:880:
[1312] 07:21:21:880: <PPP packet sent at 11/23/2009 15:21:21:880
[1312] 07:21:21:880: <Protocol = LCP, Type = Echo-Reply, Length = 0xa, Id = 0x0, Port = 1
[1312] 07:21:21:880: <C0 21 0A 00 00 08 6A 3A 47 84 00 00 00 00 00 00 |.!....j:G.......|
[1312] 07:21:21:880:
[1056] 07:21:21:900: Packet received (33 bytes) for hPort 1
[1312] 07:21:21:900: >PPP packet received at 11/23/2009 15:21:21:900
[1312] 07:21:21:900: >Protocol = CHAP, Type = Protocol specific, Length = 0x21, Id = 0xa7, Port = 1
[1312] 07:21:21:900: >C2 23 01 A7 00 1F 10 72 C7 5E 34 F0 AE 25 17 B6 |.#.....r.^4..%..|
[1312] 07:21:21:900: >1B 8D 42 50 0D 3E 2A 6C 69 6E 75 78 2D 35 75 38 |..BP.>*linux-5u8|
[1312] 07:21:21:900: >67 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |g...............|
[1312] 07:21:21:900:
[1312] 07:21:21:900: <PPP packet sent at 11/23/2009 15:21:21:900
[1312] 07:21:21:900: <Protocol = CHAP, Type = Protocol specific, Length = 0x45, Id = 0xa7, Port = 1
[1312] 07:21:21:900: <C2 23 02 A7 00 43 31 D8 63 60 B5 EE 73 21 C7 86 |.#...C1.c`..s!..|
[1312] 07:21:21:900: <FC 51 F2 F0 17 DC BF 00 00 00 00 00 00 00 00 E6 |.Q..............|
[1312] 07:21:21:900: <5F C7 BB 2F DC A2 BF 58 C1 18 76 37 DC EF D5 FE |_../...X..v7....|
[1312] 07:21:21:900: <D0 AD 85 56 AB 19 6E 00 61 64 6D 69 6E 69 73 74 |...V..n.administ|
[1312] 07:21:21:900: <72 61 74 6F 72 00 00 00 00 00 00 00 00 00 00 00 |rator...........|
[1312] 07:21:21:900:
[1312] 07:21:21:900: InsertInTimerQ called portid=4,Id=167,Protocol=c223,EventType=0,fAuth=0
[1056] 07:21:21:970: Packet received (65 bytes) for hPort 1
[1312] 07:21:21:970: >PPP packet received at 11/23/2009 15:21:21:970
[1312] 07:21:21:970: >Protocol = CHAP, Type = Protocol specific, Length = 0x41, Id = 0xa7, Port = 1
[1312] 07:21:21:970: >C2 23 03 A7 00 3F 53 3D 33 44 44 36 31 45 43 43 |.#...?S=3DD61ECC|
[1312] 07:21:21:970: >44 35 39 45 32 42 46 37 36 39 43 33 44 42 37 37 |D59E2BF769C3DB77|
[1312] 07:21:21:970: >35 36 33 46 38 39 39 46 33 46 41 42 39 30 46 41 |563F899F3FAB90FA|
[1312] 07:21:21:970: >20 4D 3D 41 63 63 65 73 73 20 67 72 61 6E 74 65 | M=Access grante|
[1312] 07:21:21:970: >64 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |d...............|
[1312] 07:21:21:970:
[1312] 07:21:21:970: RemoveFromTimerQ called portid=4,Id=167,Protocol=c223,EventType=0,fAuth=0
[1312] 07:21:21:970: MS-CHAP-MPPE-Keys set
[1312] 07:21:21:970: Checking encryption. Policy=0x0,Types=0x0,Mask=0x4
[1312] 07:21:21:970: FsmThisLayerUp called for protocol = c223, port = 1
[1312] 07:21:21:970: NotifyCaller(hPort=1, dwMsgId=17)
[1312] 07:21:21:970: NotifyCaller(hPort=1, dwMsgId=3)
[1312] 07:21:21:970: Will not initialize CP 8029
[1312] 07:21:21:970: Will not initialize CP 802b
[1312] 07:21:21:970: FsmInit called for protocol = 80fd, port = 1
[1312] 07:21:21:970: FsmReset called for protocol = 80fd, port = 1
[1312] 07:21:21:970: FsmInit called for protocol = 8021, port = 1
[1312] 07:21:21:970: FsmReset called for protocol = 8021, port = 1
[1312] 07:21:21:970: FsmOpen event received for protocol 80fd on port 1
[1312] 07:21:21:970: FsmThisLayerStarted called for protocol = 80fd, port = 1
[1312] 07:21:21:970: FsmUp event received for protocol 80fd on port 1
[1312] 07:21:21:970: <PPP packet sent at 11/23/2009 15:21:21:970
[1312] 07:21:21:970: <Protocol = CCP, Type = Configure-Req, Length = 0xc, Id = 0x5, Port = 1
[1312] 07:21:21:970: <80 FD 01 05 00 0A 12 06 01 00 00 00 00 00 00 00 |................|
[1312] 07:21:21:970:
[1312] 07:21:21:970: InsertInTimerQ called portid=4,Id=5,Protocol=80fd,EventType=0,fAuth=0
[1312] 07:21:21:970: FsmOpen event received for protocol 8021 on port 1
[1312] 07:21:21:970: FsmThisLayerStarted called for protocol = 8021, port = 1
[1312] 07:21:21:970: FsmUp event received for protocol 8021 on port 1
[1312] 07:21:21:970: <PPP packet sent at 11/23/2009 15:21:21:970
[1312] 07:21:21:970: <Protocol = IPCP, Type = Configure-Req, Length = 0x24, Id = 0x6, Port = 1
[1312] 07:21:21:970: <80 21 01 06 00 22 03 06 00 00 00 00 81 06 00 00 |.!..."..........|
[1312] 07:21:21:970: <00 00 82 06 00 00 00 00 83 06 00 00 00 00 84 06 |................|
[1312] 07:21:21:970: <00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[1312] 07:21:21:970:
[1312] 07:21:21:970: InsertInTimerQ called portid=4,Id=6,Protocol=8021,EventType=0,fAuth=0
[1056] 07:21:21:990: Packet received (12 bytes) for hPort 1
[1312] 07:21:21:990: >PPP packet received at 11/23/2009 15:21:21:990
[1312] 07:21:21:990: >Protocol = IPCP, Type = Configure-Req, Length = 0xc, Id = 0x1, Port = 1
[1312] 07:21:21:990: >80 21 01 01 00 0A 03 06 0A 05 01 01 00 00 00 00 |.!..............|
[1312] 07:21:21:990:
[1312] 07:21:21:990: <PPP packet sent at 11/23/2009 15:21:21:990
[1312] 07:21:21:990: <Protocol = IPCP, Type = Configure-Ack, Length = 0xc, Id = 0x1, Port = 1
[1312] 07:21:21:990: <80 21 02 01 00 0A 03 06 0A 05 01 01 00 00 00 00 |.!..............|
[1312] 07:21:21:990:
[1056] 07:21:22:091: Packet received (18 bytes) for hPort 1
[1312] 07:21:22:091: >PPP packet received at 11/23/2009 15:21:22:091
[1312] 07:21:22:091: >Protocol = LCP, Type = Protocol-Reject, Length = 0x12, Id = 0x3, Port = 1
[1312] 07:21:22:091: >C0 21 08 03 00 10 80 FD 01 05 00 0A 12 06 01 00 |.!..............|
[1312] 07:21:22:091: >00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[1312] 07:21:22:091:
[1312] 07:21:22:091: PPP Protocol Reject, Protocol = 80fd
[1312] 07:21:22:091: RemoveFromTimerQ called portid=4,Id=5,Protocol=80fd,EventType=0,fAuth=0
[1312] 07:21:22:091: FsmThisLayerFinished called for protocol = 80fd, port = 1
[1056] 07:21:22:091: Packet received (30 bytes) for hPort 1
[1312] 07:21:22:091: >PPP packet received at 11/23/2009 15:21:22:091
[1312] 07:21:22:091: >Protocol = IPCP, Type = Configure-Reject, Length = 0x1e, Id = 0x6, Port = 1
[1312] 07:21:22:091: >80 21 04 06 00 1C 81 06 00 00 00 00 82 06 00 00 |.!..............|
[1312] 07:21:22:091: >00 00 83 06 00 00 00 00 84 06 00 00 00 00 00 00 |................|
[1312] 07:21:22:091:
[1312] 07:21:22:091: RemoveFromTimerQ called portid=4,Id=6,Protocol=8021,EventType=0,fAuth=0
[1312] 07:21:22:091: <PPP packet sent at 11/23/2009 15:21:22:091
[1312] 07:21:22:091: <Protocol = IPCP, Type = Configure-Req, Length = 0xc, Id = 0x7, Port = 1
[1312] 07:21:22:091: <80 21 01 07 00 0A 03 06 00 00 00 00 00 00 00 00 |.!..............|
[1312] 07:21:22:091:
[1312] 07:21:22:091: InsertInTimerQ called portid=4,Id=7,Protocol=8021,EventType=0,fAuth=0
[1056] 07:21:22:141: Packet received (12 bytes) for hPort 1
[1312] 07:21:22:141: >PPP packet received at 11/23/2009 15:21:22:141
[1312] 07:21:22:141: >Protocol = IPCP, Type = Configure-Nak, Length = 0xc, Id = 0x7, Port = 1
[1312] 07:21:22:141: >80 21 03 07 00 0A 03 06 C0 A8 02 04 00 00 00 00 |.!..............|
[1312] 07:21:22:141:
[1312] 07:21:22:141: RemoveFromTimerQ called portid=4,Id=7,Protocol=8021,EventType=0,fAuth=0
[1312] 07:21:22:141: <PPP packet sent at 11/23/2009 15:21:22:141
[1312] 07:21:22:141: <Protocol = IPCP, Type = Configure-Req, Length = 0xc, Id = 0x8, Port = 1
[1312] 07:21:22:141: <80 21 01 08 00 0A 03 06 C0 A8 02 04 00 00 00 00 |.!..............|
[1312] 07:21:22:141:
[1312] 07:21:22:141: InsertInTimerQ called portid=4,Id=8,Protocol=8021,EventType=0,fAuth=0
[1056] 07:21:22:151: Packet received (12 bytes) for hPort 1
[1312] 07:21:22:151: >PPP packet received at 11/23/2009 15:21:22:151
[1312] 07:21:22:151: >Protocol = IPCP, Type = Configure-Ack, Length = 0xc, Id = 0x8, Port = 1
[1312] 07:21:22:151: >80 21 02 08 00 0A 03 06 C0 A8 02 04 00 00 00 00 |.!..............|
[1312] 07:21:22:151:
[1312] 07:21:22:151: RemoveFromTimerQ called portid=4,Id=8,Protocol=8021,EventType=0,fAuth=0
[1312] 07:21:22:151: FsmThisLayerUp called for protocol = 8021, port = 1
[1312] 07:21:22:181: Notifying IPCP of projection notification
[1312] 07:21:22:181: RasIPCPProjectionNotification returned 52
[1312] 07:21:22:181: FsmClose event received for protocol 8021 on port 1
[1312] 07:21:22:181: RemoveFromTimerQ called portid=4,Id=8,Protocol=8021,EventType=0,fAuth=0
[1312] 07:21:22:181: FsmThisLayerDown called for protocol = 8021, port = 1
[1312] 07:21:22:181: <PPP packet sent at 11/23/2009 15:21:22:181
[1312] 07:21:22:181: <Protocol = IPCP, Type = Terminate-Req, Length = 0x12, Id = 0x9, Port = 1
[1312] 07:21:22:181: <80 21 05 09 00 10 6A 3A 47 84 00 3C CD 74 00 00 |.!....j:G..<.t..|
[1312] 07:21:22:181: <00 34 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |.4..............|
[1312] 07:21:22:181:
[1312] 07:21:22:181: InsertInTimerQ called portid=4,Id=9,Protocol=8021,EventType=0,fAuth=0
[1056] 07:21:22:351: Packet received (6 bytes) for hPort 1
[1312] 07:21:22:351: >PPP packet received at 11/23/2009 15:21:22:351
[1312] 07:21:22:351: >Protocol = IPCP, Type = Terminate-Ack, Length = 0x6, Id = 0x9, Port = 1
[1312] 07:21:22:351: >80 21 06 09 00 04 00 00 00 00 00 00 00 00 00 00 |.!..............|
[1312] 07:21:22:351:
[1312] 07:21:22:351: RemoveFromTimerQ called portid=4,Id=9,Protocol=8021,EventType=0,fAuth=0
[1312] 07:21:22:351: FsmThisLayerFinished called for protocol = 8021, port = 1
[1312] 07:21:22:351: Notifying IPCP of projection notification
[1312] 07:21:22:351: RemoveFromTimerQ called portid=4,Id=0,Protocol=0,EventType=3,fAuth=0
[1312] 07:21:22:351: NotifyCaller(hPort=1, dwMsgId=4)
[1312] 07:21:22:351: NotifyCaller(hPort=1, dwMsgId=0)
[1312] 07:21:22:351: Inserting autodisconnect in timer q for port=1, sec=-1
[1312] 07:21:22:351: RemoveFromTimerQ called portid=4,Id=0,Protocol=0,EventType=1,fAuth=0
[1312] 07:21:22:351: InsertInTimerQ called portid=4,Id=0,Protocol=0,EventType=1,fAuth=0
[3136] 07:21:22:371: PPPEMSG_Stop recvd

[1312] 07:21:22:381: FsmClose event received for protocol c021 on port 1
[1312] 07:21:22:381: RemoveFromTimerQ called portid=4,Id=2,Protocol=c021,EventType=0,fAuth=0
[1312] 07:21:22:381: FsmThisLayerDown called for protocol = c021, port = 1
[1312] 07:21:22:381: FsmDown event received for protocol 80fd on port 1
[1312] 07:21:22:381: RemoveFromTimerQ called portid=4,Id=5,Protocol=80fd,EventType=0,fAuth=0
[1312] 07:21:22:381: FsmThisLayerStarted called for protocol = 80fd, port = 1
[1312] 07:21:22:381: FsmReset called for protocol = 80fd, port = 1
[1312] 07:21:22:381: FsmDown event received for protocol 8021 on port 1
[1312] 07:21:22:381: RemoveFromTimerQ called portid=4,Id=9,Protocol=8021,EventType=0,fAuth=0
[1312] 07:21:22:381: FsmReset called for protocol = 8021, port = 1
[1312] 07:21:22:381: RemoveFromTimerQ called portid=4,Id=167,Protocol=c223,EventType=0,fAuth=0
[1312] 07:21:22:381: RemoveFromTimerQ called portid=4,Id=0,Protocol=c029,EventType=0,fAuth=0
[1312] 07:21:22:381: <PPP packet sent at 11/23/2009 15:21:22:381
[1312] 07:21:22:381: <Protocol = LCP, Type = Terminate-Req, Length = 0x12, Id = 0xa, Port = 1
[1312] 07:21:22:381: <C0 21 05 0A 00 10 6A 3A 47 84 00 3C CD 74 00 00 |.!....j:G..<.t..|
[1312] 07:21:22:381: <00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 |................|
[1312] 07:21:22:381:
[1312] 07:21:22:381: InsertInTimerQ called portid=4,Id=10,Protocol=c021,EventType=0,fAuth=0
[3136] 07:21:22:381: PppStop

[3136] 07:21:22:381: PPPEMSG_Stop recvd

[1312] 07:21:22:381: FsmClose event received for protocol c021 on port 1
[1312] 07:21:22:381: RemoveFromTimerQ called portid=4,Id=10,Protocol=c021,EventType=0,fAuth=0
[1312] 07:21:22:381: FsmThisLayerFinished called for protocol = c021, port = 1
[1312] 07:21:22:381: FsmThisLayerFinished called for protocol = 80fd, port = 1: 0
[1312] 07:21:22:381: FsmThisLayerFinished called for protocol = 8021, port = 1: 0
[1312] 07:21:22:381: NotifyCaller(hPort=1, dwMsgId=10)
[1056] 07:21:23:835: PPPEMSG_LineDown recvd, hPort=1

[1312] 07:21:23:835: Line down event occurred on port 1
[1312] 07:21:23:855: FsmDown event received for protocol c021 on port 1
[1312] 07:21:23:855: RemoveFromTimerQ called portid=4,Id=10,Protocol=c021,EventType=0,fAuth=0
[1312] 07:21:23:855: FsmReset called for protocol = c021, port = 1
[1312] 07:21:23:855: RemoveFromTimerQ called portid=4,Id=0,Protocol=0,EventType=3,fAuth=0
[1312] 07:21:23:855: RemoveFromTimerQ called portid=4,Id=0,Protocol=0,EventType=7,fAuth=0
[1312] 07:21:23:855: RemoveFromTimerQ called portid=4,Id=0,Protocol=0,EventType=2,fAuth=0
[1312] 07:21:23:855: RemoveFromTimerQ called portid=4,Id=0,Protocol=0,EventType=1,fAuth=0
[1312] 07:21:23:855: RemoveFromTimerQ called portid=4,Id=0,Protocol=c029,EventType=0,fAuth=0
[1312] 07:21:23:855: LcpEnd
[1312] 07:21:23:855: Post line down event occurred on port 1
[1312] 07:21:23:855: NotifyCaller(hPort=1, dwMsgId=23)


Top
 Profile  
 
Display posts from previous:  Sort by  
Post new topic Reply to topic  [ 6 posts ] 

All times are UTC [ DST ]


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot post attachments in this forum

Search for:
cron
Powered by phpBB © 2000, 2002, 2005, 2007 phpBB Group