[Openswan Users] IPsec/L2TP VPN on Ubuntu 10.04 using Openswan version U2.6.23/K2.6.32-24-generic and xL2TP v1.2.7

Adam Crane atcapollo at hotmail.com
Mon Oct 4 04:57:21 EDT 2010


  Hello,

I am trying to setup an IPsec/L2TP VPN on Ubuntu 10.04 using Openswan 
version U2.6.23/K2.6.32-24-generic and xL2TP v1.2.7.

I am using Android 2.2 and Windows XP as my clients and I appear to 
establish the IPsec/L2TP tunnel but my clients hang up before a 
connection can be formed.
I believe the IPsec tunnel forms correctly but that there is an issue 
with the L2TP authentication, I'm a little lost now and need some 
guidance as to how to debug and get the connection up and running.

Attached are my configs and logs:


########################################################
ipsec.conf
########################################################
# /etc/ipsec.conf - Openswan IPsec configuration file
# RCSID $Id: ipsec.conf.in,v 1.16 2005/07/26 12:29:45 ken Exp $

version    2.0    # conforms to second version of ipsec.conf specification

# basic configuration
config setup
     plutodebug="control parsing"
     nat_traversal=yes
     virtual_private=%v4:10.0.0.0/8,%v4:192.168.0.0/16,%v4:172.16.0.0/12
     oe=off
     protostack=netkey
     nhelpers=0
     #plutodebug="all"


conn L2TP
     authby=secret
     auto=add
     pfs=no
     type=transport
     rekey=no

     left=192.168.1.100
     leftnexthop=192.168.1.1
     leftprotoport=17/1701

     right=%any
     rightsubnet=vhost:%no,%priv
     rightprotoport=17/1701
     forceencaps=yes



########################################################
xl2tpd.conf
########################################################
[global]
ipsec saref = yes
auth file = /etc/xl2tpd/l2tp-secrets
port = 1701
debug tunnel = yes
debug avp = yes
debug packet = yes
debug network = yes
debug state = yes

[lns default]
ip range = 192.168.1.51-192.168.1.55
local ip = 192.168.1.50
require chap = yes
refuse pap = yes
require authentication = yes
name = Zebedee
ppp debug = yes
pppoptfile = /etc/ppp/options.l2tpd
length bit = yes



########################################################
l2tp-secrets
########################################################
# Secrets for authenticating l2tp tunnels
# us    them    secret
# *        marko blah2
# zeus        marko    blah
# *    *    interop
* * password123
testuser * password123
* testuser password123



########################################################
options.l2tpd
########################################################
# Specify which DNS Servers the incoming Win95 or WinNT Connection 
should use.
# Two Servers can be remotely configured.
ms-dns 192.168.1.1

# Specify which WINS Servers the incoming connection Win95 or WinNT 
should use.
#ms-wins 10.10.0.100

# Require the peer to authenticate itself before allowing network 
packets to be sent or received.
auth

# Use hardware flow control.
crtscts

# Specifies that pppd should use a UUCP-style locks to ensure exclusive 
access to the device.
lock

# Set the MRU [Maximum Receive Unit] value to  for negotiation.
# Set the MTU [Maximum Transmit Unit] value to .
mru 1400
mtu 1400

# Don't fork to become a background process.
nodetach

# Turn on debugging. This can be turned off once everything is working.
#
debug

# Add an entry to this system's ARP table with the IP address of the 
peer and the Ethernet address of this system.
#
proxyarp

# pppd will accept the peer's idea of our local IP address,
# even if the local IP was specified in an option.
# pppd will accept the peer's idea of its (remote) IP address,
# even if the remote IP was specified in an option.
#
ipcp-accept-local
ipcp-accept-remote

# Specifies that pppd should disconnect if the link is idle for  seconds.
idle 1800

# Wait for up n milliseconds after the connect script finishes for a 
valid PPP packet from the peer.
connect-delay 5000

# Tell the windows client to to get a default route from the connection.
nodefaultroute

# Force MS-CHAP-v2 authentication since it is more secure than the other 
options.
refuse-pap
refuse-chap
refuse-mschap
require-mschap-v2
#require-mppe

# Do not sent output from plugins to the pty or the stream from clients 
may be released.
nologfd



########################################################
/var/log/syslog
########################################################
Oct  4 09:33:53 zebedee xl2tpd[1531]: network_thread: recv packet from 
192.168.1.101, size = 107, tunnel = 0, call = 0 ref=0 refhim=0
Oct  4 09:33:53 zebedee xl2tpd[1531]: get_call: allocating new tunnel 
for host 192.168.1.101, port 37435.
Oct  4 09:33:53 zebedee xl2tpd[1531]: handle_avps: handling avp's for 
tunnel 25415, call 56608
Oct  4 09:33:53 zebedee xl2tpd[1531]: message_type_avp: message type 1 
(Start-Control-Connection-Request)
Oct  4 09:33:53 zebedee xl2tpd[1531]: protocol_version_avp: peer is 
using version 1, revision 0.
Oct  4 09:33:53 zebedee xl2tpd[1531]: hostname_avp: peer reports 
hostname 'anonymous'
Oct  4 09:33:53 zebedee xl2tpd[1531]: framing_caps_avp: supported peer 
frames: async sync
Oct  4 09:33:53 zebedee xl2tpd[1531]: assigned_tunnel_avp: using peer's 
tunnel 36612
Oct  4 09:33:53 zebedee xl2tpd[1531]: receive_window_size_avp: peer 
wants RWS of 1.  Will use flow control.
Oct  4 09:33:53 zebedee xl2tpd[1531]: challenge_avp: challenge avp found
Oct  4 09:33:53 zebedee xl2tpd[1531]: control_finish: message type is 
Start-Control-Connection-Request(1).  Tunnel is 36612, call is 0.
Oct  4 09:33:53 zebedee xl2tpd[1531]: control_finish: sending SCCRP
Oct  4 09:33:55 zebedee xl2tpd[1531]: build_fdset: closing down tunnel 53658
Oct  4 09:33:55 zebedee xl2tpd[1531]: network_thread: recv packet from 
192.168.1.101, size = 107, tunnel = 0, call = 0 ref=0 refhim=0
Oct  4 09:33:55 zebedee xl2tpd[1531]: get_call: allocating new tunnel 
for host 192.168.1.101, port 37435.
Oct  4 09:33:55 zebedee xl2tpd[1531]: handle_avps: handling avp's for 
tunnel 39225, call 34571
Oct  4 09:33:55 zebedee xl2tpd[1531]: message_type_avp: message type 1 
(Start-Control-Connection-Request)
Oct  4 09:33:55 zebedee xl2tpd[1531]: protocol_version_avp: peer is 
using version 1, revision 0.
Oct  4 09:33:55 zebedee xl2tpd[1531]: hostname_avp: peer reports 
hostname 'anonymous'
Oct  4 09:33:55 zebedee xl2tpd[1531]: framing_caps_avp: supported peer 
frames: async sync
Oct  4 09:33:55 zebedee xl2tpd[1531]: assigned_tunnel_avp: using peer's 
tunnel 36612
Oct  4 09:33:55 zebedee xl2tpd[1531]: receive_window_size_avp: peer 
wants RWS of 1.  Will use flow control.
Oct  4 09:33:55 zebedee xl2tpd[1531]: challenge_avp: challenge avp found
Oct  4 09:33:55 zebedee xl2tpd[1531]: control_finish: message type is 
Start-Control-Connection-Request(1).  Tunnel is 36612, call is 0.
Oct  4 09:33:55 zebedee xl2tpd[1531]: control_finish: Peer requested 
tunnel 36612 twice, ignoring second one.
Oct  4 09:33:55 zebedee xl2tpd[1531]: build_fdset: closing down tunnel 39225
Oct  4 09:33:55 zebedee xl2tpd[1531]: network_thread: recv packet from 
192.168.1.101, size = 20, tunnel = 25415, call = 0 ref=0 refhim=0
Oct  4 09:33:55 zebedee xl2tpd[1531]: handle_avps: handling avp's for 
tunnel 25415, call 56608
Oct  4 09:33:55 zebedee xl2tpd[1531]: message_type_avp: message type 3 
(Start-Control-Connection-Connected)
Oct  4 09:33:55 zebedee xl2tpd[1531]: control_finish: message type is 
Start-Control-Connection-Connected(3).  Tunnel is 36612, call is 0.
Oct  4 09:33:55 zebedee xl2tpd[1531]: Connection established to 
192.168.1.101, 37435.  Local: 25415, Remote: 36612 (ref=0/0).  LNS 
session is 'default'
Oct  4 09:33:55 zebedee xl2tpd[1531]: network_thread: recv packet from 
192.168.1.101, size = 38, tunnel = 25415, call = 0 ref=0 refhim=0
Oct  4 09:33:55 zebedee xl2tpd[1531]: handle_avps: handling avp's for 
tunnel 25415, call 56608
Oct  4 09:33:55 zebedee xl2tpd[1531]: message_type_avp: message type 10 
(Incoming-Call-Request)
Oct  4 09:33:55 zebedee xl2tpd[1531]: message_type_avp: new incoming call
Oct  4 09:33:55 zebedee xl2tpd[1531]: assigned_call_avp: using peer's 
call 1096
Oct  4 09:33:55 zebedee xl2tpd[1531]: call_serno_avp: serial number is 
-934305952
Oct  4 09:33:55 zebedee xl2tpd[1531]: control_finish: message type is 
Incoming-Call-Request(10).  Tunnel is 36612, call is 0.
Oct  4 09:33:55 zebedee xl2tpd[1531]: control_finish: Sending ICRP
Oct  4 09:33:55 zebedee xl2tpd[1531]: network_thread: recv packet from 
192.168.1.101, size = 40, tunnel = 25415, call = 40632 ref=0 refhim=0
Oct  4 09:33:55 zebedee xl2tpd[1531]: handle_avps: handling avp's for 
tunnel 25415, call 40632
Oct  4 09:33:55 zebedee xl2tpd[1531]: message_type_avp: message type 12 
(Incoming-Call-Connected)
Oct  4 09:33:55 zebedee xl2tpd[1531]: tx_speed_avp: transmit baud rate 
is 100000000
Oct  4 09:33:55 zebedee xl2tpd[1531]: frame_type_avp: peer uses: async 
frames
Oct  4 09:33:55 zebedee xl2tpd[1531]: control_finish: message type is 
Incoming-Call-Connected(12).  Tunnel is 36612, call is 1096.
Oct  4 09:33:55 zebedee xl2tpd[1531]: start_pppd: I'm running:
Oct  4 09:33:55 zebedee xl2tpd[1531]: "/usr/sbin/pppd"
Oct  4 09:33:55 zebedee xl2tpd[1531]: "passive"
Oct  4 09:33:55 zebedee xl2tpd[1531]: "nodetach"
Oct  4 09:33:55 zebedee xl2tpd[1531]: "192.168.1.50:192.168.1.51"
Oct  4 09:33:55 zebedee xl2tpd[1531]: "refuse-pap"
Oct  4 09:33:55 zebedee xl2tpd[1531]: "auth"
Oct  4 09:33:55 zebedee xl2tpd[1531]: "require-chap"
Oct  4 09:33:55 zebedee xl2tpd[1531]: "name"
Oct  4 09:33:55 zebedee xl2tpd[1531]: "Zebedee"
Oct  4 09:33:55 zebedee xl2tpd[1531]: "debug"
Oct  4 09:33:55 zebedee xl2tpd[1531]: "file"
Oct  4 09:33:55 zebedee xl2tpd[1531]: "/etc/ppp/options.l2tpd"
Oct  4 09:33:55 zebedee xl2tpd[1531]: "/dev/pts/3"
Oct  4 09:33:55 zebedee xl2tpd[1531]: Call established with 
192.168.1.101, Local: 40632, Remote: 1096, Serial: -934305952
Oct  4 09:33:55 zebedee xl2tpd[1531]: network_thread: recv packet from 
192.168.1.101, size = 34, tunnel = 25415, call = 40632 ref=0 refhim=0
Oct  4 09:33:55 zebedee xl2tpd[1531]: child_handler : pppd exited for 
call 1096 with code 2
Oct  4 09:33:55 zebedee xl2tpd[1531]: call_close: Call 40632 to 
192.168.1.101 disconnected
Oct  4 09:33:55 zebedee xl2tpd[1531]: network_thread: recv packet from 
192.168.1.101, size = 26, tunnel = 25415, call = 40632 ref=0 refhim=0
Oct  4 09:33:55 zebedee xl2tpd[1531]: write_packet: tty is not open yet.
Oct  4 09:33:55 zebedee xl2tpd[1531]: network_thread: bad packet
Oct  4 09:33:56 zebedee xl2tpd[1531]: network_thread: select timeout
Oct  4 09:33:58 zebedee xl2tpd[1531]: last message repeated 4 times
Oct  4 09:33:58 zebedee xl2tpd[1531]: network_thread: recv packet from 
192.168.1.101, size = 26, tunnel = 25415, call = 40632 ref=0 refhim=0
Oct  4 09:33:58 zebedee xl2tpd[1531]: write_packet: tty is not open yet.
Oct  4 09:33:58 zebedee xl2tpd[1531]: network_thread: bad packet
Oct  4 09:33:59 zebedee xl2tpd[1531]: network_thread: select timeout
Oct  4 09:34:00 zebedee xl2tpd[1531]: network_thread: select timeout
Oct  4 09:34:00 zebedee xl2tpd[1531]: Maximum retries exceeded for 
tunnel 25415.  Closing.
Oct  4 09:34:00 zebedee xl2tpd[1531]: network_thread: recv packet from 
192.168.1.101, size = 36, tunnel = 25415, call = 0 ref=0 refhim=0
Oct  4 09:34:00 zebedee xl2tpd[1531]: handle_avps: handling avp's for 
tunnel 25415, call 56608
Oct  4 09:34:00 zebedee xl2tpd[1531]: message_type_avp: message type 4 
(Stop-Control-Connection-Notification)
Oct  4 09:34:00 zebedee xl2tpd[1531]: assigned_tunnel_avp: using peer's 
tunnel 36612
Oct  4 09:34:00 zebedee xl2tpd[1531]: result_code_avp: avp is incorrect 
size.  8 < 10
Oct  4 09:34:00 zebedee xl2tpd[1531]: handle_avps: Bad exit status 
handling attribute 1 (Result Code) on mandatory packet.
Oct  4 09:34:00 zebedee xl2tpd[1531]: handle_packet: bad AVP handling!
Oct  4 09:34:00 zebedee xl2tpd[1531]: network_thread: bad packet
Oct  4 09:34:00 zebedee xl2tpd[1531]: build_fdset: closing down tunnel 25415
Oct  4 09:34:00 zebedee xl2tpd[1531]: Terminating pppd: sending TERM 
signal to pid 4020
Oct  4 09:34:00 zebedee xl2tpd[1531]: Connection 36612 closed to 
192.168.1.101, port 37435 (Result Code: expected at least 10, got 8)
Oct  4 09:34:01 zebedee xl2tpd[1531]: network_thread: select timeout
Oct  4 09:34:05 zebedee xl2tpd[1531]: last message repeated 4 times
Oct  4 09:34:05 zebedee xl2tpd[1531]: Unable to deliver closing message 
for tunnel 25415. Destroying anyway.



########################################################
/var/log/auth.log
########################################################
Oct  4 09:33:51 zebedee pluto[27098]: packet from 192.168.1.101:500: 
received Vendor ID payload [RFC 3947] method set to=109
Oct  4 09:33:51 zebedee pluto[27098]: packet from 192.168.1.101:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02] meth=107, but 
already using method 109
Oct  4 09:33:51 zebedee pluto[27098]: packet from 192.168.1.101:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] meth=106, 
but already using method 109
Oct  4 09:33:51 zebedee pluto[27098]: packet from 192.168.1.101:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-00]
Oct  4 09:33:51 zebedee pluto[27098]: packet from 192.168.1.101:500: 
ignoring Vendor ID payload [FRAGMENTATION 80000000]
Oct  4 09:33:51 zebedee pluto[27098]: | ****parse IPsec DOI SIT:
Oct  4 09:33:51 zebedee pluto[27098]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Oct  4 09:33:51 zebedee pluto[27098]: | ****parse ISAKMP Proposal Payload:
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_NONE
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 208
Oct  4 09:33:51 zebedee pluto[27098]: |    proposal number: 1
Oct  4 09:33:51 zebedee pluto[27098]: |    protocol ID: PROTO_ISAKMP
Oct  4 09:33:51 zebedee pluto[27098]: |    SPI size: 0
Oct  4 09:33:51 zebedee pluto[27098]: |    number of transforms: 6
Oct  4 09:33:51 zebedee pluto[27098]: | *****parse ISAKMP Transform 
Payload (ISAKMP):
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: ISAKMP_NEXT_T
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 32
Oct  4 09:33:51 zebedee pluto[27098]: |    transform number: 1
Oct  4 09:33:51 zebedee pluto[27098]: |    transform ID: KEY_IKE
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_LIFE_TYPE
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_LIFE_DURATION
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 28800
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: 
OAKLEY_ENCRYPTION_ALGORITHM
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 5
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: 
OAKLEY_AUTHENTICATION_METHOD
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_HASH_ALGORITHM
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 2
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_GROUP_DESCRIPTION
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 2
Oct  4 09:33:51 zebedee pluto[27098]: | *****parse ISAKMP Transform 
Payload (ISAKMP):
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: ISAKMP_NEXT_T
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 32
Oct  4 09:33:51 zebedee pluto[27098]: |    transform number: 2
Oct  4 09:33:51 zebedee pluto[27098]: |    transform ID: KEY_IKE
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_LIFE_TYPE
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_LIFE_DURATION
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 28800
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: 
OAKLEY_ENCRYPTION_ALGORITHM
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 5
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: 
OAKLEY_AUTHENTICATION_METHOD
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_HASH_ALGORITHM
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_GROUP_DESCRIPTION
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 2
Oct  4 09:33:51 zebedee pluto[27098]: | *****parse ISAKMP Transform 
Payload (ISAKMP):
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: ISAKMP_NEXT_T
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 32
Oct  4 09:33:51 zebedee pluto[27098]: |    transform number: 3
Oct  4 09:33:51 zebedee pluto[27098]: |    transform ID: KEY_IKE
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_LIFE_TYPE
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_LIFE_DURATION
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 28800
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: 
OAKLEY_ENCRYPTION_ALGORITHM
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: 
OAKLEY_AUTHENTICATION_METHOD
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_HASH_ALGORITHM
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 2
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_GROUP_DESCRIPTION
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 2
Oct  4 09:33:51 zebedee pluto[27098]: | *****parse ISAKMP Transform 
Payload (ISAKMP):
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: ISAKMP_NEXT_T
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 32
Oct  4 09:33:51 zebedee pluto[27098]: |    transform number: 4
Oct  4 09:33:51 zebedee pluto[27098]: |    transform ID: KEY_IKE
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_LIFE_TYPE
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_LIFE_DURATION
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 28800
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: 
OAKLEY_ENCRYPTION_ALGORITHM
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: 
OAKLEY_AUTHENTICATION_METHOD
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_HASH_ALGORITHM
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_GROUP_DESCRIPTION
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 2
Oct  4 09:33:51 zebedee pluto[27098]: | *****parse ISAKMP Transform 
Payload (ISAKMP):
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: ISAKMP_NEXT_T
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 36
Oct  4 09:33:51 zebedee pluto[27098]: |    transform number: 5
Oct  4 09:33:51 zebedee pluto[27098]: |    transform ID: KEY_IKE
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_LIFE_TYPE
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_LIFE_DURATION
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 28800
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: 
OAKLEY_ENCRYPTION_ALGORITHM
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 7
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_KEY_LENGTH
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 128
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: 
OAKLEY_AUTHENTICATION_METHOD
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_HASH_ALGORITHM
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 2
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_GROUP_DESCRIPTION
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 2
Oct  4 09:33:51 zebedee pluto[27098]: | *****parse ISAKMP Transform 
Payload (ISAKMP):
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_NONE
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 36
Oct  4 09:33:51 zebedee pluto[27098]: |    transform number: 6
Oct  4 09:33:51 zebedee pluto[27098]: |    transform ID: KEY_IKE
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_LIFE_TYPE
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_LIFE_DURATION
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 28800
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: 
OAKLEY_ENCRYPTION_ALGORITHM
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 7
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_KEY_LENGTH
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 128
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: 
OAKLEY_AUTHENTICATION_METHOD
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_HASH_ALGORITHM
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_GROUP_DESCRIPTION
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 2
Oct  4 09:33:51 zebedee pluto[27098]: | instantiated "L2TP" for 
192.168.1.101
Oct  4 09:33:51 zebedee pluto[27098]: | creating state object #4 at 
0x8985138
Oct  4 09:33:51 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:33:51 zebedee pluto[27098]: | ICOOKIE:  89 53 8f b1  f7 16 39 c7
Oct  4 09:33:51 zebedee pluto[27098]: | RCOOKIE:  8f f0 5a 43  1d a2 bd 37
Oct  4 09:33:51 zebedee pluto[27098]: | state hash entry 26
Oct  4 09:33:51 zebedee pluto[27098]: | inserting state object #4 on 
chain 26
Oct  4 09:33:51 zebedee pluto[27098]: | inserting event 
EVENT_SO_DISCARD, timeout in 0 seconds for #4
Oct  4 09:33:51 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #4: 
responding to Main Mode from unknown peer 192.168.1.101
Oct  4 09:33:51 zebedee pluto[27098]: | ****parse IPsec DOI SIT:
Oct  4 09:33:51 zebedee pluto[27098]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Oct  4 09:33:51 zebedee pluto[27098]: | ****parse ISAKMP Proposal Payload:
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_NONE
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 208
Oct  4 09:33:51 zebedee pluto[27098]: |    proposal number: 1
Oct  4 09:33:51 zebedee pluto[27098]: |    protocol ID: PROTO_ISAKMP
Oct  4 09:33:51 zebedee pluto[27098]: |    SPI size: 0
Oct  4 09:33:51 zebedee pluto[27098]: |    number of transforms: 6
Oct  4 09:33:51 zebedee pluto[27098]: | *****parse ISAKMP Transform 
Payload (ISAKMP):
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: ISAKMP_NEXT_T
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 32
Oct  4 09:33:51 zebedee pluto[27098]: |    transform number: 1
Oct  4 09:33:51 zebedee pluto[27098]: |    transform ID: KEY_IKE
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_LIFE_TYPE
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: |    [1 is OAKLEY_LIFE_SECONDS]
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_LIFE_DURATION
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 28800
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: 
OAKLEY_ENCRYPTION_ALGORITHM
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 5
Oct  4 09:33:51 zebedee pluto[27098]: |    [5 is OAKLEY_3DES_CBC]
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: 
OAKLEY_AUTHENTICATION_METHOD
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:51 zebedee pluto[27098]: |    [1 is OAKLEY_PRESHARED_KEY]
Oct  4 09:33:51 zebedee pluto[27098]: | started looking for secret for 
192.168.1.100->192.168.1.101 of kind PPK_PSK
Oct  4 09:33:51 zebedee pluto[27098]: | instantiating him to 0.0.0.0
Oct  4 09:33:51 zebedee pluto[27098]: | actually looking for secret for 
192.168.1.100->%any of kind PPK_PSK
Oct  4 09:33:51 zebedee pluto[27098]: | 1: compared key %any to 
192.168.1.100 / %any -> 2
Oct  4 09:33:51 zebedee pluto[27098]: | 2: compared key %any to 
192.168.1.100 / %any -> 2
Oct  4 09:33:51 zebedee pluto[27098]: | line 16: match=2
Oct  4 09:33:51 zebedee pluto[27098]: | best_match 0>2 best=0x8983c48 
(line=16)
Oct  4 09:33:51 zebedee pluto[27098]: | concluding with best_match=2 
best=0x8983c48 (lineno=16)
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_HASH_ALGORITHM
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 2
Oct  4 09:33:51 zebedee pluto[27098]: |    [2 is OAKLEY_SHA1]
Oct  4 09:33:51 zebedee pluto[27098]: | ******parse ISAKMP Oakley attribute:
Oct  4 09:33:51 zebedee pluto[27098]: |    af+type: OAKLEY_GROUP_DESCRIPTION
Oct  4 09:33:51 zebedee pluto[27098]: |    length/value: 2
Oct  4 09:33:51 zebedee pluto[27098]: |    [2 is OAKLEY_GROUP_MODP1024]
Oct  4 09:33:51 zebedee pluto[27098]: | Oakley Transform 1 accepted
Oct  4 09:33:51 zebedee pluto[27098]: | complete state transition with 
STF_OK
Oct  4 09:33:51 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #4: 
transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
Oct  4 09:33:51 zebedee pluto[27098]: | sending reply packet to 
192.168.1.101:500 (from port 500)
Oct  4 09:33:51 zebedee pluto[27098]: | sending 136 bytes for 
STATE_MAIN_R0 through eth0:500 to 192.168.1.101:500 (using #4)
Oct  4 09:33:51 zebedee pluto[27098]: | inserting event 
EVENT_RETRANSMIT, timeout in 10 seconds for #4
Oct  4 09:33:51 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #4: 
STATE_MAIN_R1: sent MR1, expecting MI2
Oct  4 09:33:51 zebedee pluto[27098]: | modecfg pull: noquirk 
policy:push not-client
Oct  4 09:33:51 zebedee pluto[27098]: | phase 1 is done, looking for 
phase 2 to unpend
Oct  4 09:33:51 zebedee pluto[27098]: | * processed 0 messages from 
cryptographic helpers
Oct  4 09:33:51 zebedee pluto[27098]: | next event EVENT_PENDING_DDNS in 
0 seconds
Oct  4 09:33:51 zebedee pluto[27098]: | *time to handle event
Oct  4 09:33:51 zebedee pluto[27098]: | handling event EVENT_PENDING_DDNS
Oct  4 09:33:51 zebedee pluto[27098]: | event after this is 
EVENT_RETRANSMIT in 10 seconds
Oct  4 09:33:51 zebedee pluto[27098]: | inserting event 
EVENT_PENDING_DDNS, timeout in 60 seconds
Oct  4 09:33:51 zebedee pluto[27098]: | next event EVENT_RETRANSMIT in 
10 seconds for #4
Oct  4 09:33:51 zebedee pluto[27098]: |
Oct  4 09:33:51 zebedee pluto[27098]: | *received 228 bytes from 
192.168.1.101:500 on eth0 (port=500)
Oct  4 09:33:51 zebedee pluto[27098]: | **parse ISAKMP Message:
Oct  4 09:33:51 zebedee pluto[27098]: |    initiator cookie:
Oct  4 09:33:51 zebedee pluto[27098]: |   89 53 8f b1  f7 16 39 c7
Oct  4 09:33:51 zebedee pluto[27098]: |    responder cookie:
Oct  4 09:33:51 zebedee pluto[27098]: |   8f f0 5a 43  1d a2 bd 37
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: ISAKMP_NEXT_KE
Oct  4 09:33:51 zebedee pluto[27098]: |    ISAKMP version: ISAKMP 
Version 1.0 (rfc2407)
Oct  4 09:33:51 zebedee pluto[27098]: |    exchange type: ISAKMP_XCHG_IDPROT
Oct  4 09:33:51 zebedee pluto[27098]: |    flags: none
Oct  4 09:33:51 zebedee pluto[27098]: |    message ID:  00 00 00 00
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 228
Oct  4 09:33:51 zebedee pluto[27098]: |  processing version=1.0 packet 
with exchange type=ISAKMP_XCHG_IDPROT (2)
Oct  4 09:33:51 zebedee pluto[27098]: | ICOOKIE:  89 53 8f b1  f7 16 39 c7
Oct  4 09:33:51 zebedee pluto[27098]: | RCOOKIE:  8f f0 5a 43  1d a2 bd 37
Oct  4 09:33:51 zebedee pluto[27098]: | state hash entry 26
Oct  4 09:33:51 zebedee pluto[27098]: | v1 peer and cookies match on #4, 
provided msgid 00000000 vs 00000000
Oct  4 09:33:51 zebedee pluto[27098]: | v1 state object #4 found, in 
STATE_MAIN_R1
Oct  4 09:33:51 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:33:51 zebedee pluto[27098]: | got payload 0x10(ISAKMP_NEXT_KE) 
needed: 0x410 opt: 0x102080
Oct  4 09:33:51 zebedee pluto[27098]: | ***parse ISAKMP Key Exchange 
Payload:
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_NONCE
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 132
Oct  4 09:33:51 zebedee pluto[27098]: | got payload 
0x400(ISAKMP_NEXT_NONCE) needed: 0x400 opt: 0x102080
Oct  4 09:33:51 zebedee pluto[27098]: | ***parse ISAKMP Nonce Payload:
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_NAT-D
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 20
Oct  4 09:33:51 zebedee pluto[27098]: | got payload 
0x100000(ISAKMP_NEXT_NAT-D) needed: 0x0 opt: 0x102080
Oct  4 09:33:51 zebedee pluto[27098]: | ***parse ISAKMP NAT-D Payload:
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_NAT-D
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 24
Oct  4 09:33:51 zebedee pluto[27098]: | got payload 
0x100000(ISAKMP_NEXT_NAT-D) needed: 0x0 opt: 0x102080
Oct  4 09:33:51 zebedee pluto[27098]: | ***parse ISAKMP NAT-D Payload:
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_NONE
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 24
Oct  4 09:33:51 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #4: 
NAT-Traversal: Result using RFC 3947 (NAT-Traversal): both are NATed
Oct  4 09:33:51 zebedee pluto[27098]: | inserting event 
EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct  4 09:33:51 zebedee pluto[27098]: | helper -1 doing build_kenonce op 
id: 0
Oct  4 09:33:51 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:33:51 zebedee pluto[27098]: | started looking for secret for 
192.168.1.100->192.168.1.101 of kind PPK_PSK
Oct  4 09:33:51 zebedee pluto[27098]: | instantiating him to 0.0.0.0
Oct  4 09:33:51 zebedee pluto[27098]: | actually looking for secret for 
192.168.1.100->%any of kind PPK_PSK
Oct  4 09:33:51 zebedee pluto[27098]: | 1: compared key %any to 
192.168.1.100 / %any -> 2
Oct  4 09:33:51 zebedee pluto[27098]: | 2: compared key %any to 
192.168.1.100 / %any -> 2
Oct  4 09:33:51 zebedee pluto[27098]: | line 16: match=2
Oct  4 09:33:51 zebedee pluto[27098]: | best_match 0>2 best=0x8983c48 
(line=16)
Oct  4 09:33:51 zebedee pluto[27098]: | concluding with best_match=2 
best=0x8983c48 (lineno=16)
Oct  4 09:33:51 zebedee pluto[27098]: | parent1 type: 7 group: 2 len: 2668
Oct  4 09:33:51 zebedee pluto[27098]: | helper -1 doing compute dh+iv op 
id: 1769346
Oct  4 09:33:51 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:33:51 zebedee pluto[27098]: | complete state transition with 
STF_OK
Oct  4 09:33:51 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #4: 
transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
Oct  4 09:33:51 zebedee pluto[27098]: | sending reply packet to 
192.168.1.101:500 (from port 500)
Oct  4 09:33:51 zebedee pluto[27098]: | sending 228 bytes for 
STATE_MAIN_R1 through eth0:500 to 192.168.1.101:500 (using #4)
Oct  4 09:33:51 zebedee pluto[27098]: | inserting event 
EVENT_RETRANSMIT, timeout in 10 seconds for #4
Oct  4 09:33:51 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #4: 
STATE_MAIN_R2: sent MR2, expecting MI3
Oct  4 09:33:51 zebedee pluto[27098]: | modecfg pull: noquirk 
policy:push not-client
Oct  4 09:33:51 zebedee pluto[27098]: | phase 1 is done, looking for 
phase 2 to unpend
Oct  4 09:33:51 zebedee pluto[27098]: | complete state transition with 
STF_INLINE
Oct  4 09:33:51 zebedee pluto[27098]: | * processed 0 messages from 
cryptographic helpers
Oct  4 09:33:51 zebedee pluto[27098]: | next event EVENT_RETRANSMIT in 
10 seconds for #4
Oct  4 09:33:51 zebedee pluto[27098]: | next event EVENT_RETRANSMIT in 
10 seconds for #4
Oct  4 09:33:51 zebedee pluto[27098]: |
Oct  4 09:33:51 zebedee pluto[27098]: | *received 76 bytes from 
192.168.1.101:4500 on eth0 (port=4500)
Oct  4 09:33:51 zebedee pluto[27098]: | **parse ISAKMP Message:
Oct  4 09:33:51 zebedee pluto[27098]: |    initiator cookie:
Oct  4 09:33:51 zebedee pluto[27098]: |   89 53 8f b1  f7 16 39 c7
Oct  4 09:33:51 zebedee pluto[27098]: |    responder cookie:
Oct  4 09:33:51 zebedee pluto[27098]: |   8f f0 5a 43  1d a2 bd 37
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: ISAKMP_NEXT_ID
Oct  4 09:33:51 zebedee pluto[27098]: |    ISAKMP version: ISAKMP 
Version 1.0 (rfc2407)
Oct  4 09:33:51 zebedee pluto[27098]: |    exchange type: ISAKMP_XCHG_IDPROT
Oct  4 09:33:51 zebedee pluto[27098]: |    flags: ISAKMP_FLAG_ENCRYPTION
Oct  4 09:33:51 zebedee pluto[27098]: |    message ID:  00 00 00 00
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 76
Oct  4 09:33:51 zebedee pluto[27098]: |  processing version=1.0 packet 
with exchange type=ISAKMP_XCHG_IDPROT (2)
Oct  4 09:33:51 zebedee pluto[27098]: | ICOOKIE:  89 53 8f b1  f7 16 39 c7
Oct  4 09:33:51 zebedee pluto[27098]: | RCOOKIE:  8f f0 5a 43  1d a2 bd 37
Oct  4 09:33:51 zebedee pluto[27098]: | state hash entry 26
Oct  4 09:33:51 zebedee pluto[27098]: | v1 peer and cookies match on #4, 
provided msgid 00000000 vs 00000000
Oct  4 09:33:51 zebedee pluto[27098]: | v1 state object #4 found, in 
STATE_MAIN_R2
Oct  4 09:33:51 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:33:51 zebedee pluto[27098]: | got payload 0x20(ISAKMP_NEXT_ID) 
needed: 0x120 opt: 0x2080
Oct  4 09:33:51 zebedee pluto[27098]: | ***parse ISAKMP Identification 
Payload:
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_HASH
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 12
Oct  4 09:33:51 zebedee pluto[27098]: |    ID type: ID_IPV4_ADDR
Oct  4 09:33:51 zebedee pluto[27098]: |    DOI specific A: 17
Oct  4 09:33:51 zebedee pluto[27098]: |    DOI specific B: 500
Oct  4 09:33:51 zebedee pluto[27098]: |      obj:   c0 a8 01 65  00 00 
00 18  e8 8c 3f cb
Oct  4 09:33:51 zebedee pluto[27098]: | got payload 
0x100(ISAKMP_NEXT_HASH) needed: 0x100 opt: 0x2080
Oct  4 09:33:51 zebedee pluto[27098]: | ***parse ISAKMP Hash Payload:
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_NONE
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 24
Oct  4 09:33:51 zebedee pluto[27098]: | removing 12 bytes of padding
Oct  4 09:33:51 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #4: Main 
mode peer ID is ID_IPV4_ADDR: '192.168.1.101'
Oct  4 09:33:51 zebedee pluto[27098]: | started looking for secret for 
192.168.1.100->192.168.1.101 of kind PPK_PSK
Oct  4 09:33:51 zebedee pluto[27098]: | instantiating him to 0.0.0.0
Oct  4 09:33:51 zebedee pluto[27098]: | actually looking for secret for 
192.168.1.100->%any of kind PPK_PSK
Oct  4 09:33:51 zebedee pluto[27098]: | 1: compared key %any to 
192.168.1.100 / %any -> 2
Oct  4 09:33:51 zebedee pluto[27098]: | 2: compared key %any to 
192.168.1.100 / %any -> 2
Oct  4 09:33:51 zebedee pluto[27098]: | line 16: match=2
Oct  4 09:33:51 zebedee pluto[27098]: | best_match 0>2 best=0x8983c48 
(line=16)
Oct  4 09:33:51 zebedee pluto[27098]: | concluding with best_match=2 
best=0x8983c48 (lineno=16)
Oct  4 09:33:51 zebedee pluto[27098]: | started looking for secret for 
192.168.1.100->192.168.1.101 of kind PPK_PSK
Oct  4 09:33:51 zebedee pluto[27098]: | instantiating him to 0.0.0.0
Oct  4 09:33:51 zebedee pluto[27098]: | actually looking for secret for 
192.168.1.100->%any of kind PPK_PSK
Oct  4 09:33:51 zebedee pluto[27098]: | 1: compared key %any to 
192.168.1.100 / %any -> 2
Oct  4 09:33:51 zebedee pluto[27098]: | 2: compared key %any to 
192.168.1.100 / %any -> 2
Oct  4 09:33:51 zebedee pluto[27098]: | line 16: match=2
Oct  4 09:33:51 zebedee pluto[27098]: | best_match 0>2 best=0x8983c48 
(line=16)
Oct  4 09:33:51 zebedee pluto[27098]: | concluding with best_match=2 
best=0x8983c48 (lineno=16)
Oct  4 09:33:51 zebedee pluto[27098]: | offered CA: '%none'
Oct  4 09:33:51 zebedee pluto[27098]: | thinking about whether to send 
my certificate:
Oct  4 09:33:51 zebedee pluto[27098]: |   I have RSA key: 
OAKLEY_PRESHARED_KEY cert.type: CERT_NONE
Oct  4 09:33:51 zebedee pluto[27098]: |   sendcert: CERT_ALWAYSSEND and 
I did not get a certificate request
Oct  4 09:33:51 zebedee pluto[27098]: |   so do not send cert.
Oct  4 09:33:51 zebedee pluto[27098]: | I did not send a certificate 
because digital signatures are not being used. (PSK)
Oct  4 09:33:51 zebedee pluto[27098]: | complete state transition with 
STF_OK
Oct  4 09:33:51 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #4: 
transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
Oct  4 09:33:51 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:33:51 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #4: new 
NAT mapping for #4, was 192.168.1.101:500, now 192.168.1.101:4500
Oct  4 09:33:51 zebedee pluto[27098]: | sending reply packet to 
192.168.1.101:4500 (from port 4500)
Oct  4 09:33:51 zebedee pluto[27098]: | sending 76 bytes for 
STATE_MAIN_R2 through eth0:4500 to 192.168.1.101:4500 (using #4)
Oct  4 09:33:51 zebedee pluto[27098]: | inserting event EVENT_SA_EXPIRE, 
timeout in 28800 seconds for #4
Oct  4 09:33:51 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #4: 
STATE_MAIN_R3: sent MR3, ISAKMP SA established 
{auth=OAKLEY_PRESHARED_KEY cipher=oakley_3des_cbc_192 prf=oakley_sha 
group=modp1024}
Oct  4 09:33:51 zebedee pluto[27098]: | modecfg pull: noquirk 
policy:push not-client
Oct  4 09:33:51 zebedee pluto[27098]: | phase 1 is done, looking for 
phase 2 to unpend
Oct  4 09:33:51 zebedee pluto[27098]: | * processed 0 messages from 
cryptographic helpers
Oct  4 09:33:51 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 20 seconds
Oct  4 09:33:51 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 20 seconds
Oct  4 09:33:51 zebedee pluto[27098]: |
Oct  4 09:33:51 zebedee pluto[27098]: | *received 92 bytes from 
192.168.1.101:4500 on eth0 (port=4500)
Oct  4 09:33:51 zebedee pluto[27098]: | **parse ISAKMP Message:
Oct  4 09:33:51 zebedee pluto[27098]: |    initiator cookie:
Oct  4 09:33:51 zebedee pluto[27098]: |   89 53 8f b1  f7 16 39 c7
Oct  4 09:33:51 zebedee pluto[27098]: |    responder cookie:
Oct  4 09:33:51 zebedee pluto[27098]: |   8f f0 5a 43  1d a2 bd 37
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_HASH
Oct  4 09:33:51 zebedee pluto[27098]: |    ISAKMP version: ISAKMP 
Version 1.0 (rfc2407)
Oct  4 09:33:51 zebedee pluto[27098]: |    exchange type: ISAKMP_XCHG_INFO
Oct  4 09:33:51 zebedee pluto[27098]: |    flags: ISAKMP_FLAG_ENCRYPTION
Oct  4 09:33:51 zebedee pluto[27098]: |    message ID:  9e 92 03 56
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 92
Oct  4 09:33:51 zebedee pluto[27098]: |  processing version=1.0 packet 
with exchange type=ISAKMP_XCHG_INFO (5)
Oct  4 09:33:51 zebedee pluto[27098]: | ICOOKIE:  89 53 8f b1  f7 16 39 c7
Oct  4 09:33:51 zebedee pluto[27098]: | RCOOKIE:  8f f0 5a 43  1d a2 bd 37
Oct  4 09:33:51 zebedee pluto[27098]: | state hash entry 26
Oct  4 09:33:51 zebedee pluto[27098]: | peer and cookies match on #4, 
provided msgid 00000000 vs 00000000/00000000
Oct  4 09:33:51 zebedee pluto[27098]: | p15 state object #4 found, in 
STATE_MAIN_R3
Oct  4 09:33:51 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:33:51 zebedee pluto[27098]: | got payload 
0x100(ISAKMP_NEXT_HASH) needed: 0x100 opt: 0x0
Oct  4 09:33:51 zebedee pluto[27098]: | ***parse ISAKMP Hash Payload:
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: ISAKMP_NEXT_N
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 24
Oct  4 09:33:51 zebedee pluto[27098]: | got payload 0x800(ISAKMP_NEXT_N) 
needed: 0x0 opt: 0x0
Oct  4 09:33:51 zebedee pluto[27098]: | ***parse ISAKMP Notification 
Payload:
Oct  4 09:33:51 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_NONE
Oct  4 09:33:51 zebedee pluto[27098]: |    length: 28
Oct  4 09:33:51 zebedee pluto[27098]: |    DOI: ISAKMP_DOI_IPSEC
Oct  4 09:33:51 zebedee pluto[27098]: |    protocol ID: 1
Oct  4 09:33:51 zebedee pluto[27098]: |    SPI size: 16
Oct  4 09:33:51 zebedee pluto[27098]: |    Notify Message Type: 
IPSEC_INITIAL_CONTACT
Oct  4 09:33:51 zebedee pluto[27098]: | removing 12 bytes of padding
Oct  4 09:33:51 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #4: 
ignoring informational payload, type IPSEC_INITIAL_CONTACT msgid=00000000
Oct  4 09:33:51 zebedee pluto[27098]: | info:  89 53 8f b1  f7 16 39 c7  
8f f0 5a 43  1d a2 bd 37
Oct  4 09:33:51 zebedee pluto[27098]: | processing informational 
IPSEC_INITIAL_CONTACT (24578)
Oct  4 09:33:51 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #4: 
received and ignored informational message
Oct  4 09:33:51 zebedee pluto[27098]: | complete state transition with 
STF_IGNORE
Oct  4 09:33:51 zebedee pluto[27098]: | * processed 0 messages from 
cryptographic helpers
Oct  4 09:33:51 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 20 seconds
Oct  4 09:33:51 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 20 seconds
Oct  4 09:33:52 zebedee pluto[27098]: |
Oct  4 09:33:52 zebedee pluto[27098]: | *received 284 bytes from 
192.168.1.101:4500 on eth0 (port=4500)
Oct  4 09:33:52 zebedee pluto[27098]: | **parse ISAKMP Message:
Oct  4 09:33:52 zebedee pluto[27098]: |    initiator cookie:
Oct  4 09:33:52 zebedee pluto[27098]: |   89 53 8f b1  f7 16 39 c7
Oct  4 09:33:52 zebedee pluto[27098]: |    responder cookie:
Oct  4 09:33:52 zebedee pluto[27098]: |   8f f0 5a 43  1d a2 bd 37
Oct  4 09:33:52 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_HASH
Oct  4 09:33:52 zebedee pluto[27098]: |    ISAKMP version: ISAKMP 
Version 1.0 (rfc2407)
Oct  4 09:33:52 zebedee pluto[27098]: |    exchange type: ISAKMP_XCHG_QUICK
Oct  4 09:33:52 zebedee pluto[27098]: |    flags: ISAKMP_FLAG_ENCRYPTION
Oct  4 09:33:52 zebedee pluto[27098]: |    message ID:  a5 27 05 c7
Oct  4 09:33:52 zebedee pluto[27098]: |    length: 284
Oct  4 09:33:52 zebedee pluto[27098]: |  processing version=1.0 packet 
with exchange type=ISAKMP_XCHG_QUICK (32)
Oct  4 09:33:52 zebedee pluto[27098]: | ICOOKIE:  89 53 8f b1  f7 16 39 c7
Oct  4 09:33:52 zebedee pluto[27098]: | RCOOKIE:  8f f0 5a 43  1d a2 bd 37
Oct  4 09:33:52 zebedee pluto[27098]: | state hash entry 26
Oct  4 09:33:52 zebedee pluto[27098]: | v1 peer and cookies match on #4, 
provided msgid a52705c7 vs 00000000
Oct  4 09:33:52 zebedee pluto[27098]: | v1 state object not found
Oct  4 09:33:52 zebedee pluto[27098]: | ICOOKIE:  89 53 8f b1  f7 16 39 c7
Oct  4 09:33:52 zebedee pluto[27098]: | RCOOKIE:  8f f0 5a 43  1d a2 bd 37
Oct  4 09:33:52 zebedee pluto[27098]: | state hash entry 26
Oct  4 09:33:52 zebedee pluto[27098]: | v1 peer and cookies match on #4, 
provided msgid 00000000 vs 00000000
Oct  4 09:33:52 zebedee pluto[27098]: | v1 state object #4 found, in 
STATE_MAIN_R3
Oct  4 09:33:52 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:33:52 zebedee pluto[27098]: | got payload 
0x100(ISAKMP_NEXT_HASH) needed: 0x502 opt: 0x200030
Oct  4 09:33:52 zebedee pluto[27098]: | ***parse ISAKMP Hash Payload:
Oct  4 09:33:52 zebedee pluto[27098]: |    next payload type: ISAKMP_NEXT_SA
Oct  4 09:33:52 zebedee pluto[27098]: |    length: 24
Oct  4 09:33:52 zebedee pluto[27098]: | got payload 0x2(ISAKMP_NEXT_SA) 
needed: 0x402 opt: 0x200030
Oct  4 09:33:52 zebedee pluto[27098]: | ***parse ISAKMP Security 
Association Payload:
Oct  4 09:33:52 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_NONCE
Oct  4 09:33:52 zebedee pluto[27098]: |    length: 176
Oct  4 09:33:52 zebedee pluto[27098]: |    DOI: ISAKMP_DOI_IPSEC
Oct  4 09:33:52 zebedee pluto[27098]: | got payload 
0x400(ISAKMP_NEXT_NONCE) needed: 0x400 opt: 0x200030
Oct  4 09:33:52 zebedee pluto[27098]: | ***parse ISAKMP Nonce Payload:
Oct  4 09:33:52 zebedee pluto[27098]: |    next payload type: ISAKMP_NEXT_ID
Oct  4 09:33:52 zebedee pluto[27098]: |    length: 20
Oct  4 09:33:52 zebedee pluto[27098]: | got payload 0x20(ISAKMP_NEXT_ID) 
needed: 0x0 opt: 0x200030
Oct  4 09:33:52 zebedee pluto[27098]: | ***parse ISAKMP Identification 
Payload (IPsec DOI):
Oct  4 09:33:52 zebedee pluto[27098]: |    next payload type: ISAKMP_NEXT_ID
Oct  4 09:33:52 zebedee pluto[27098]: |    length: 12
Oct  4 09:33:52 zebedee pluto[27098]: |    ID type: ID_IPV4_ADDR
Oct  4 09:33:52 zebedee pluto[27098]: |    Protocol ID: 17
Oct  4 09:33:52 zebedee pluto[27098]: |    port: 0
Oct  4 09:33:52 zebedee pluto[27098]: |      obj:   c0 a8 01 65  00 00 
00 0c  01 11 06 a5
Oct  4 09:33:52 zebedee pluto[27098]: | got payload 0x20(ISAKMP_NEXT_ID) 
needed: 0x0 opt: 0x200030
Oct  4 09:33:52 zebedee pluto[27098]: | ***parse ISAKMP Identification 
Payload (IPsec DOI):
Oct  4 09:33:52 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_NONE
Oct  4 09:33:52 zebedee pluto[27098]: |    length: 12
Oct  4 09:33:52 zebedee pluto[27098]: |    ID type: ID_IPV4_ADDR
Oct  4 09:33:52 zebedee pluto[27098]: |    Protocol ID: 17
Oct  4 09:33:52 zebedee pluto[27098]: |    port: 1701
Oct  4 09:33:52 zebedee pluto[27098]: |      obj:   c0 a8 01 64  e3 e0 
a1 b3  9f a4 95 86
Oct  4 09:33:52 zebedee pluto[27098]: | removing 12 bytes of padding
Oct  4 09:33:52 zebedee pluto[27098]: | peer client is 192.168.1.101
Oct  4 09:33:52 zebedee pluto[27098]: | peer client protocol/port is 17/0
Oct  4 09:33:52 zebedee pluto[27098]: | our client is 192.168.1.100
Oct  4 09:33:52 zebedee pluto[27098]: | our client protocol/port is 17/1701
Oct  4 09:33:52 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #4: the 
peer proposed: 192.168.1.100/32:17/1701 -> 192.168.1.101/32:17/1701
Oct  4 09:33:52 zebedee pluto[27098]: | using (something - hopefully the 
IP we are NAT'ed too) for transport mode connection "L2TP"
Oct  4 09:33:52 zebedee pluto[27098]: | duplicating state object #4
Oct  4 09:33:52 zebedee pluto[27098]: | creating state object #5 at 
0x8985b98
Oct  4 09:33:52 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:33:52 zebedee pluto[27098]: | ICOOKIE:  89 53 8f b1  f7 16 39 c7
Oct  4 09:33:52 zebedee pluto[27098]: | RCOOKIE:  8f f0 5a 43  1d a2 bd 37
Oct  4 09:33:52 zebedee pluto[27098]: | state hash entry 26
Oct  4 09:33:52 zebedee pluto[27098]: | inserting state object #5 on 
chain 26
Oct  4 09:33:52 zebedee pluto[27098]: | inserting event 
EVENT_SO_DISCARD, timeout in 0 seconds for #5
Oct  4 09:33:52 zebedee pluto[27098]: | ****parse IPsec DOI SIT:
Oct  4 09:33:52 zebedee pluto[27098]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Oct  4 09:33:52 zebedee pluto[27098]: | ****parse ISAKMP Proposal Payload:
Oct  4 09:33:52 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_NONE
Oct  4 09:33:52 zebedee pluto[27098]: |    length: 164
Oct  4 09:33:52 zebedee pluto[27098]: |    proposal number: 1
Oct  4 09:33:52 zebedee pluto[27098]: |    protocol ID: PROTO_IPSEC_ESP
Oct  4 09:33:52 zebedee pluto[27098]: |    SPI size: 4
Oct  4 09:33:52 zebedee pluto[27098]: |    number of transforms: 6
Oct  4 09:33:52 zebedee pluto[27098]: | parsing 4 raw bytes of ISAKMP 
Proposal Payload into SPI
Oct  4 09:33:52 zebedee pluto[27098]: | SPI  0b ac 53 d0
Oct  4 09:33:52 zebedee pluto[27098]: | *****parse ISAKMP Transform 
Payload (ESP):
Oct  4 09:33:52 zebedee pluto[27098]: |    next payload type: ISAKMP_NEXT_T
Oct  4 09:33:52 zebedee pluto[27098]: |    length: 24
Oct  4 09:33:52 zebedee pluto[27098]: |    transform number: 1
Oct  4 09:33:52 zebedee pluto[27098]: |    transform ID: ESP_3DES
Oct  4 09:33:52 zebedee pluto[27098]: | ******parse ISAKMP IPsec DOI 
attribute:
Oct  4 09:33:52 zebedee pluto[27098]: |    af+type: SA_LIFE_TYPE
Oct  4 09:33:52 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:52 zebedee pluto[27098]: |    [1 is SA_LIFE_TYPE_SECONDS]
Oct  4 09:33:52 zebedee pluto[27098]: | ******parse ISAKMP IPsec DOI 
attribute:
Oct  4 09:33:52 zebedee pluto[27098]: |    af+type: SA_LIFE_DURATION
Oct  4 09:33:52 zebedee pluto[27098]: |    length/value: 28800
Oct  4 09:33:52 zebedee pluto[27098]: | ******parse ISAKMP IPsec DOI 
attribute:
Oct  4 09:33:52 zebedee pluto[27098]: |    af+type: ENCAPSULATION_MODE
Oct  4 09:33:52 zebedee pluto[27098]: |    length/value: 4
Oct  4 09:33:52 zebedee pluto[27098]: |    [4 is 
ENCAPSULATION_MODE_UDP_TRANSPORT]
Oct  4 09:33:52 zebedee pluto[27098]: | ******parse ISAKMP IPsec DOI 
attribute:
Oct  4 09:33:52 zebedee pluto[27098]: |    af+type: AUTH_ALGORITHM
Oct  4 09:33:52 zebedee pluto[27098]: |    length/value: 2
Oct  4 09:33:52 zebedee pluto[27098]: |    [2 is AUTH_ALGORITHM_HMAC_SHA1]
Oct  4 09:33:52 zebedee pluto[27098]: | helper -1 doing build_nonce op 
id: 1972698
Oct  4 09:33:52 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:33:52 zebedee pluto[27098]: | ****parse IPsec DOI SIT:
Oct  4 09:33:52 zebedee pluto[27098]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Oct  4 09:33:52 zebedee pluto[27098]: | ****parse ISAKMP Proposal Payload:
Oct  4 09:33:52 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_NONE
Oct  4 09:33:52 zebedee pluto[27098]: |    length: 164
Oct  4 09:33:52 zebedee pluto[27098]: |    proposal number: 1
Oct  4 09:33:52 zebedee pluto[27098]: |    protocol ID: PROTO_IPSEC_ESP
Oct  4 09:33:52 zebedee pluto[27098]: |    SPI size: 4
Oct  4 09:33:52 zebedee pluto[27098]: |    number of transforms: 6
Oct  4 09:33:52 zebedee pluto[27098]: | parsing 4 raw bytes of ISAKMP 
Proposal Payload into SPI
Oct  4 09:33:52 zebedee pluto[27098]: | SPI  0b ac 53 d0
Oct  4 09:33:52 zebedee pluto[27098]: | *****parse ISAKMP Transform 
Payload (ESP):
Oct  4 09:33:52 zebedee pluto[27098]: |    next payload type: ISAKMP_NEXT_T
Oct  4 09:33:52 zebedee pluto[27098]: |    length: 24
Oct  4 09:33:52 zebedee pluto[27098]: |    transform number: 1
Oct  4 09:33:52 zebedee pluto[27098]: |    transform ID: ESP_3DES
Oct  4 09:33:52 zebedee pluto[27098]: | ******parse ISAKMP IPsec DOI 
attribute:
Oct  4 09:33:52 zebedee pluto[27098]: |    af+type: SA_LIFE_TYPE
Oct  4 09:33:52 zebedee pluto[27098]: |    length/value: 1
Oct  4 09:33:52 zebedee pluto[27098]: |    [1 is SA_LIFE_TYPE_SECONDS]
Oct  4 09:33:52 zebedee pluto[27098]: | ******parse ISAKMP IPsec DOI 
attribute:
Oct  4 09:33:52 zebedee pluto[27098]: |    af+type: SA_LIFE_DURATION
Oct  4 09:33:52 zebedee pluto[27098]: |    length/value: 28800
Oct  4 09:33:52 zebedee pluto[27098]: | ******parse ISAKMP IPsec DOI 
attribute:
Oct  4 09:33:52 zebedee pluto[27098]: |    af+type: ENCAPSULATION_MODE
Oct  4 09:33:52 zebedee pluto[27098]: |    length/value: 4
Oct  4 09:33:52 zebedee pluto[27098]: |    [4 is 
ENCAPSULATION_MODE_UDP_TRANSPORT]
Oct  4 09:33:52 zebedee pluto[27098]: | ******parse ISAKMP IPsec DOI 
attribute:
Oct  4 09:33:52 zebedee pluto[27098]: |    af+type: AUTH_ALGORITHM
Oct  4 09:33:52 zebedee pluto[27098]: |    length/value: 2
Oct  4 09:33:52 zebedee pluto[27098]: |    [2 is AUTH_ALGORITHM_HMAC_SHA1]
Oct  4 09:33:52 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #5: 
responding to Quick Mode proposal {msgid:c70527a5}
Oct  4 09:33:52 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #5:     
us: 192.168.1.100<192.168.1.100>[+S=C]:17/1701---192.168.1.1
Oct  4 09:33:52 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #5:   
them: 192.168.1.101[+S=C]:17/1701
Oct  4 09:33:52 zebedee pluto[27098]: | compute_proto_keymat:needed_len 
(after ESP enc)=24
Oct  4 09:33:52 zebedee pluto[27098]: | compute_proto_keymat:needed_len 
(after ESP auth)=44
Oct  4 09:33:52 zebedee pluto[27098]: | install_inbound_ipsec_sa() 
checking if we can route
Oct  4 09:33:52 zebedee pluto[27098]: | route owner of "L2TP"[4] 
192.168.1.101 unrouted: NULL; eroute owner: NULL
Oct  4 09:33:52 zebedee pluto[27098]: | could_route called for L2TP 
(kind=CK_INSTANCE)
Oct  4 09:33:52 zebedee pluto[27098]: |    routing is easy, or has 
resolvable near-conflict
Oct  4 09:33:52 zebedee pluto[27098]: | checking if this is a 
replacement state
Oct  4 09:33:52 zebedee pluto[27098]: |   st=0x8985b98 ost=(nil) 
st->serialno=#5 ost->serialno=#0
Oct  4 09:33:52 zebedee pluto[27098]: | installing outgoing SA now as 
refhim=0
Oct  4 09:33:52 zebedee pluto[27098]: | outgoing SA has refhim=4294901761
Oct  4 09:33:52 zebedee pluto[27098]: | add inbound eroute 
192.168.1.101/32:0 --17-> 192.168.1.100/32:1701 => 
tun.10000 at 192.168.1.100 (raw_eroute)
Oct  4 09:33:52 zebedee pluto[27098]: | raw_eroute result=1
Oct  4 09:33:52 zebedee pluto[27098]: | complete state transition with 
STF_OK
Oct  4 09:33:52 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #5: 
transition from state STATE_QUICK_R0 to state STATE_QUICK_R1
Oct  4 09:33:52 zebedee pluto[27098]: | sending reply packet to 
192.168.1.101:4500 (from port 4500)
Oct  4 09:33:52 zebedee pluto[27098]: | sending 148 bytes for 
STATE_QUICK_R0 through eth0:4500 to 192.168.1.101:4500 (using #5)
Oct  4 09:33:52 zebedee pluto[27098]: | inserting event 
EVENT_RETRANSMIT, timeout in 10 seconds for #5
Oct  4 09:33:52 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #5: 
STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2
Oct  4 09:33:52 zebedee pluto[27098]: | modecfg pull: noquirk 
policy:push not-client
Oct  4 09:33:52 zebedee pluto[27098]: | phase 1 is done, looking for 
phase 2 to unpend
Oct  4 09:33:52 zebedee pluto[27098]: | complete state transition with 
STF_INLINE
Oct  4 09:33:52 zebedee pluto[27098]: | * processed 0 messages from 
cryptographic helpers
Oct  4 09:33:52 zebedee pluto[27098]: | next event EVENT_RETRANSMIT in 
10 seconds for #5
Oct  4 09:33:52 zebedee pluto[27098]: | next event EVENT_RETRANSMIT in 
10 seconds for #5
Oct  4 09:33:52 zebedee pluto[27098]: |
Oct  4 09:33:52 zebedee pluto[27098]: | *received 68 bytes from 
192.168.1.101:4500 on eth0 (port=4500)
Oct  4 09:33:52 zebedee pluto[27098]: | **parse ISAKMP Message:
Oct  4 09:33:52 zebedee pluto[27098]: |    initiator cookie:
Oct  4 09:33:52 zebedee pluto[27098]: |   89 53 8f b1  f7 16 39 c7
Oct  4 09:33:52 zebedee pluto[27098]: |    responder cookie:
Oct  4 09:33:52 zebedee pluto[27098]: |   8f f0 5a 43  1d a2 bd 37
Oct  4 09:33:52 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_HASH
Oct  4 09:33:52 zebedee pluto[27098]: |    ISAKMP version: ISAKMP 
Version 1.0 (rfc2407)
Oct  4 09:33:52 zebedee pluto[27098]: |    exchange type: ISAKMP_XCHG_QUICK
Oct  4 09:33:52 zebedee pluto[27098]: |    flags: ISAKMP_FLAG_ENCRYPTION
Oct  4 09:33:52 zebedee pluto[27098]: |    message ID:  a5 27 05 c7
Oct  4 09:33:52 zebedee pluto[27098]: |    length: 68
Oct  4 09:33:52 zebedee pluto[27098]: |  processing version=1.0 packet 
with exchange type=ISAKMP_XCHG_QUICK (32)
Oct  4 09:33:52 zebedee pluto[27098]: | ICOOKIE:  89 53 8f b1  f7 16 39 c7
Oct  4 09:33:52 zebedee pluto[27098]: | RCOOKIE:  8f f0 5a 43  1d a2 bd 37
Oct  4 09:33:52 zebedee pluto[27098]: | state hash entry 26
Oct  4 09:33:52 zebedee pluto[27098]: | v1 peer and cookies match on #5, 
provided msgid a52705c7 vs a52705c7
Oct  4 09:33:52 zebedee pluto[27098]: | v1 state object #5 found, in 
STATE_QUICK_R1
Oct  4 09:33:52 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:33:52 zebedee pluto[27098]: | got payload 
0x100(ISAKMP_NEXT_HASH) needed: 0x100 opt: 0x0
Oct  4 09:33:52 zebedee pluto[27098]: | ***parse ISAKMP Hash Payload:
Oct  4 09:33:52 zebedee pluto[27098]: |    next payload type: 
ISAKMP_NEXT_NONE
Oct  4 09:33:52 zebedee pluto[27098]: |    length: 24
Oct  4 09:33:52 zebedee pluto[27098]: | removing 16 bytes of padding
Oct  4 09:33:52 zebedee pluto[27098]: | install_ipsec_sa() for #5: 
outbound only
Oct  4 09:33:52 zebedee pluto[27098]: | route owner of "L2TP"[4] 
192.168.1.101 unrouted: NULL; eroute owner: NULL
Oct  4 09:33:52 zebedee pluto[27098]: | could_route called for L2TP 
(kind=CK_INSTANCE)
Oct  4 09:33:52 zebedee pluto[27098]: | sr for #5: unrouted
Oct  4 09:33:52 zebedee pluto[27098]: | route owner of "L2TP"[4] 
192.168.1.101 unrouted: NULL; eroute owner: NULL
Oct  4 09:33:52 zebedee pluto[27098]: | eroute_connection add eroute 
192.168.1.100/32:1701 --17-> 192.168.1.101/32:0 => 
esp.bac53d0 at 192.168.1.101 (raw_eroute)
Oct  4 09:33:52 zebedee pluto[27098]: | raw_eroute result=1
Oct  4 09:33:52 zebedee pluto[27098]: | command executing up-host
Oct  4 09:33:52 zebedee pluto[27098]: | executing up-host: 2>&1 
PLUTO_VERB='up-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='L2TP' 
PLUTO_INTERFACE='eth0' PLUTO_NEXT_HOP='192.168.1.1' 
PLUTO_ME='192.168.1.100' PLUTO_MY_ID='192.168.1.100' 
PLUTO_MY_CLIENT='192.168.1.100/32' PLUTO_MY_CLIENT_NET='192.168.1.100' 
PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='1701' 
PLUTO_MY_PROTOCOL='17' PLUTO_PEER='192.168.1.101' 
PLUTO_PEER_ID='192.168.1.101' PLUTO_PEER_CLIENT='192.168.1.101/32' 
PLUTO_PEER_CLIENT_NET='192.168.1.101' 
PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='1701' 
PLUTO_PEER_PROTOCOL='17' PLUTO_PEER_CA='' PLUTO_STACK='netkey'  
PLUTO_CONN_POLICY='PSK+ENCRYPT+DONTREKEY+IKEv2ALLOW' 
PLUTO_XAUTH_USERNAME=''  ipsec _updown
Oct  4 09:33:52 zebedee pluto[27098]: | popen(): cmd is 680 chars long
Oct  4 09:33:52 zebedee pluto[27098]: | cmd(   0):2>&1 
PLUTO_VERB='up-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='L2TP' PLUTO_INTE:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd(  80):RFACE='eth0' 
PLUTO_NEXT_HOP='192.168.1.1' PLUTO_ME='192.168.1.100' PLUTO_MY_ID=':
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 160):192.168.1.100' 
PLUTO_MY_CLIENT='192.168.1.100/32' PLUTO_MY_CLIENT_NET='192.168.1:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 240):.100' 
PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='1701' PLUTO_MY_PROTO:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 320):COL='17' 
PLUTO_PEER='192.168.1.101' PLUTO_PEER_ID='192.168.1.101' PLUTO_PEER_CLI:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 400):ENT='192.168.1.101/32' 
PLUTO_PEER_CLIENT_NET='192.168.1.101' PLUTO_PEER_CLIENT_M:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 480):ASK='255.255.255.255' 
PLUTO_PEER_PORT='1701' PLUTO_PEER_PROTOCOL='17' PLUTO_PEER:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 560):_CA='' 
PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+DONTREKEY+IKEv2ALLOW:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 640):' 
PLUTO_XAUTH_USERNAME=''  ipsec _updown:
Oct  4 09:33:52 zebedee pluto[27098]: | route_and_eroute: 
firewall_notified: true
Oct  4 09:33:52 zebedee pluto[27098]: | command executing prepare-host
Oct  4 09:33:52 zebedee pluto[27098]: | executing prepare-host: 2>&1 
PLUTO_VERB='prepare-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='L2TP' 
PLUTO_INTERFACE='eth0' PLUTO_NEXT_HOP='192.168.1.1' 
PLUTO_ME='192.168.1.100' PLUTO_MY_ID='192.168.1.100' 
PLUTO_MY_CLIENT='192.168.1.100/32' PLUTO_MY_CLIENT_NET='192.168.1.100' 
PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='1701' 
PLUTO_MY_PROTOCOL='17' PLUTO_PEER='192.168.1.101' 
PLUTO_PEER_ID='192.168.1.101' PLUTO_PEER_CLIENT='192.168.1.101/32' 
PLUTO_PEER_CLIENT_NET='192.168.1.101' 
PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='1701' 
PLUTO_PEER_PROTOCOL='17' PLUTO_PEER_CA='' PLUTO_STACK='netkey'  
PLUTO_CONN_POLICY='PSK+ENCRYPT+DONTREKEY+IKEv2ALLOW' 
PLUTO_XAUTH_USERNAME=''  ipsec _updown
Oct  4 09:33:52 zebedee pluto[27098]: | popen(): cmd is 685 chars long
Oct  4 09:33:52 zebedee pluto[27098]: | cmd(   0):2>&1 
PLUTO_VERB='prepare-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='L2TP' PLUTO:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd(  80):_INTERFACE='eth0' 
PLUTO_NEXT_HOP='192.168.1.1' PLUTO_ME='192.168.1.100' PLUTO_MY:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 160):_ID='192.168.1.100' 
PLUTO_MY_CLIENT='192.168.1.100/32' PLUTO_MY_CLIENT_NET='192.:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 240):168.1.100' 
PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='1701' PLUTO_MY_:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 320):PROTOCOL='17' 
PLUTO_PEER='192.168.1.101' PLUTO_PEER_ID='192.168.1.101' PLUTO_PEE:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 
400):R_CLIENT='192.168.1.101/32' PLUTO_PEER_CLIENT_NET='192.168.1.101' 
PLUTO_PEER_CLI:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 
480):ENT_MASK='255.255.255.255' PLUTO_PEER_PORT='1701' 
PLUTO_PEER_PROTOCOL='17' PLUTO:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 560):_PEER_CA='' 
PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+DONTREKEY+IKEv2:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 640):ALLOW' 
PLUTO_XAUTH_USERNAME=''  ipsec _updown:
Oct  4 09:33:52 zebedee pluto[27098]: | command executing route-host
Oct  4 09:33:52 zebedee pluto[27098]: | executing route-host: 2>&1 
PLUTO_VERB='route-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='L2TP' 
PLUTO_INTERFACE='eth0' PLUTO_NEXT_HOP='192.168.1.1' 
PLUTO_ME='192.168.1.100' PLUTO_MY_ID='192.168.1.100' 
PLUTO_MY_CLIENT='192.168.1.100/32' PLUTO_MY_CLIENT_NET='192.168.1.100' 
PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='1701' 
PLUTO_MY_PROTOCOL='17' PLUTO_PEER='192.168.1.101' 
PLUTO_PEER_ID='192.168.1.101' PLUTO_PEER_CLIENT='192.168.1.101/32' 
PLUTO_PEER_CLIENT_NET='192.168.1.101' 
PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='1701' 
PLUTO_PEER_PROTOCOL='17' PLUTO_PEER_CA='' PLUTO_STACK='netkey'  
PLUTO_CONN_POLICY='PSK+ENCRYPT+DONTREKEY+IKEv2ALLOW' 
PLUTO_XAUTH_USERNAME=''  ipsec _updown
Oct  4 09:33:52 zebedee pluto[27098]: | popen(): cmd is 683 chars long
Oct  4 09:33:52 zebedee pluto[27098]: | cmd(   0):2>&1 
PLUTO_VERB='route-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='L2TP' PLUTO_I:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd(  80):NTERFACE='eth0' 
PLUTO_NEXT_HOP='192.168.1.1' PLUTO_ME='192.168.1.100' PLUTO_MY_I:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 160):D='192.168.1.100' 
PLUTO_MY_CLIENT='192.168.1.100/32' PLUTO_MY_CLIENT_NET='192.16:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 240):8.1.100' 
PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='1701' PLUTO_MY_PR:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 320):OTOCOL='17' 
PLUTO_PEER='192.168.1.101' PLUTO_PEER_ID='192.168.1.101' PLUTO_PEER_:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 
400):CLIENT='192.168.1.101/32' PLUTO_PEER_CLIENT_NET='192.168.1.101' 
PLUTO_PEER_CLIEN:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 
480):T_MASK='255.255.255.255' PLUTO_PEER_PORT='1701' 
PLUTO_PEER_PROTOCOL='17' PLUTO_P:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 560):EER_CA='' 
PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+DONTREKEY+IKEv2AL:
Oct  4 09:33:52 zebedee pluto[27098]: | cmd( 640):LOW' 
PLUTO_XAUTH_USERNAME=''  ipsec _updown:
Oct  4 09:33:52 zebedee pluto[27098]: | route_and_eroute: instance 
"L2TP"[4] 192.168.1.101, setting eroute_owner 
{spd=0x8984e40,sr=0x8984e40} to #5 (was #0) (newest_ipsec_sa=#0)
Oct  4 09:33:52 zebedee pluto[27098]: | complete state transition with 
STF_OK
Oct  4 09:33:52 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #5: 
transition from state STATE_QUICK_R1 to state STATE_QUICK_R2
Oct  4 09:33:52 zebedee pluto[27098]: | inserting event EVENT_SA_EXPIRE, 
timeout in 28800 seconds for #5
Oct  4 09:33:52 zebedee pluto[27098]: "L2TP"[4] 192.168.1.101 #5: 
STATE_QUICK_R2: IPsec SA established transport mode {ESP/NAT=>0x0bac53d0 
<0x9395b9c7 xfrm=3DES_0-HMAC_SHA1 NATOA=none NATD=192.168.1.101:4500 
DPD=none}
Oct  4 09:33:52 zebedee pluto[27098]: | modecfg pull: noquirk 
policy:push not-client
Oct  4 09:33:52 zebedee pluto[27098]: | phase 1 is done, looking for 
phase 2 to unpend
Oct  4 09:33:52 zebedee pluto[27098]: | * processed 0 messages from 
cryptographic helpers
Oct  4 09:33:52 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 19 seconds
Oct  4 09:33:52 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 19 seconds
Oct  4 09:33:55 zebedee sudo: testuser : TTY=pts/1 ; PWD=/home/testuser 
; USER=root ; COMMAND=/bin/cat /var/log/auth.log
Oct  4 09:34:01 zebedee pluto[27098]: |
Oct  4 09:34:01 zebedee pluto[27098]: | rejected packet:
Oct  4 09:34:01 zebedee pluto[27098]: |   0b ac 53 d0  00 00 00 0e  04 
a2 36 f6  27 e3 46 87
Oct  4 09:34:01 zebedee pluto[27098]: |   d9 56 b3 77  0f 8b 2f 1c  83 
16 dc a7  7e a6 d7 b6
Oct  4 09:34:01 zebedee pluto[27098]: |   30 7a 3b af  09 44 87 31  40 
95 92 99  8b a7 b6 81
Oct  4 09:34:01 zebedee pluto[27098]: |   97 e4 97 6f  a2 a5 de 83  74 
e5 2c d7  30 c5 17 cd
Oct  4 09:34:01 zebedee pluto[27098]: |   4c 59 b4 5e  6c e8 7b 2c  33 
b7 ed 3b  33 4d 49 c5
Oct  4 09:34:01 zebedee pluto[27098]: |   03 be f1 6d  62 e4 5f 8f  5a 
42 65 05  ca 6e 15 ac
Oct  4 09:34:01 zebedee pluto[27098]: |   89 16 5f a5  27 77 d3 b7  eb 
03 29 b9  cb 9f b7 f3
Oct  4 09:34:01 zebedee pluto[27098]: |   4f 2a 06 e4
Oct  4 09:34:01 zebedee pluto[27098]: | control:
Oct  4 09:34:01 zebedee pluto[27098]: |   18 00 00 00  00 00 00 00  08 
00 00 00  02 00 00 00
Oct  4 09:34:01 zebedee pluto[27098]: |   c0 a8 01 64  c0 a8 01 64  2c 
00 00 00  00 00 00 00
Oct  4 09:34:01 zebedee pluto[27098]: |   0b 00 00 00  6f 00 00 00  02 
03 03 00  00 00 00 00
Oct  4 09:34:01 zebedee pluto[27098]: |   00 00 00 00  02 00 00 00  c0 
a8 01 65  00 00 00 00
Oct  4 09:34:01 zebedee pluto[27098]: |   00 00 00 00
Oct  4 09:34:01 zebedee pluto[27098]: | name:
Oct  4 09:34:01 zebedee pluto[27098]: |   02 00 11 94  c0 a8 01 65  00 
00 00 00  00 00 00 00
Oct  4 09:34:01 zebedee pluto[27098]: ERROR: asynchronous network error 
report on eth0 (sport=4500) for message to 192.168.1.101 port 4500, 
complainant 192.168.1.101: Connection refused [errno 111, origin ICMP 
type 3 code 3 (not authenticated)]
Oct  4 09:34:01 zebedee pluto[27098]: | * processed 0 messages from 
cryptographic helpers
Oct  4 09:34:01 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 10 seconds
Oct  4 09:34:01 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 10 seconds
Oct  4 09:34:02 zebedee pluto[27098]: |
Oct  4 09:34:02 zebedee pluto[27098]: | rejected packet:
Oct  4 09:34:02 zebedee pluto[27098]: |   0b ac 53 d0  00 00 00 0f  aa 
ed 72 04  98 fb ca da
Oct  4 09:34:02 zebedee pluto[27098]: |   71 16 3a f6  61 a1 d2 79  c3 
e2 63 2c  59 b6 35 72
Oct  4 09:34:02 zebedee pluto[27098]: |   6c 21 7b 61  46 56 44 6e  d7 
56 03 5d  f3 67 44 1b
Oct  4 09:34:02 zebedee pluto[27098]: |   fd 24 f2 dd  5b 7e 3e 44  6b 
a6 2d 3e  0d 24 b2 92
Oct  4 09:34:02 zebedee pluto[27098]: |   31 aa 45 87  c9 0f ea 08  9c 
a0 54 28  b6 2e 5b 6f
Oct  4 09:34:02 zebedee pluto[27098]: |   4e 40 fc a8  cc d6 80 53  ef 
dd 55 8c  90 fc 2d 2f
Oct  4 09:34:02 zebedee pluto[27098]: |   f3 54 f1 fb  49 53 78 73  4b 
51 ad bd  22 85 2f 74
Oct  4 09:34:02 zebedee pluto[27098]: |   84 2f 8f 6a
Oct  4 09:34:02 zebedee pluto[27098]: | control:
Oct  4 09:34:02 zebedee pluto[27098]: |   18 00 00 00  00 00 00 00  08 
00 00 00  02 00 00 00
Oct  4 09:34:02 zebedee pluto[27098]: |   c0 a8 01 64  c0 a8 01 64  2c 
00 00 00  00 00 00 00
Oct  4 09:34:02 zebedee pluto[27098]: |   0b 00 00 00  6f 00 00 00  02 
03 03 00  00 00 00 00
Oct  4 09:34:02 zebedee pluto[27098]: |   00 00 00 00  02 00 00 00  c0 
a8 01 65  00 00 00 00
Oct  4 09:34:02 zebedee pluto[27098]: |   00 00 00 00
Oct  4 09:34:02 zebedee pluto[27098]: | name:
Oct  4 09:34:02 zebedee pluto[27098]: |   02 00 11 94  c0 a8 01 65  00 
00 00 00  00 00 00 00
Oct  4 09:34:02 zebedee pluto[27098]: ERROR: asynchronous network error 
report on eth0 (sport=4500) for message to 192.168.1.101 port 4500, 
complainant 192.168.1.101: Connection refused [errno 111, origin ICMP 
type 3 code 3 (not authenticated)]
Oct  4 09:34:02 zebedee pluto[27098]: | * processed 0 messages from 
cryptographic helpers
Oct  4 09:34:02 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 9 seconds
Oct  4 09:34:02 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 9 seconds
Oct  4 09:34:03 zebedee pluto[27098]: |
Oct  4 09:34:03 zebedee pluto[27098]: | rejected packet:
Oct  4 09:34:03 zebedee pluto[27098]: |   0b ac 53 d0  00 00 00 10  29 
5c 08 dd  b1 4a 07 58
Oct  4 09:34:03 zebedee pluto[27098]: |   d7 4d c8 65  09 c7 35 ae  10 
55 2b 68  50 d8 54 86
Oct  4 09:34:03 zebedee pluto[27098]: |   2a f2 38 2e  09 f3 02 5e  9e 
2d 4f 8f  bb 51 7a 6c
Oct  4 09:34:03 zebedee pluto[27098]: |   c7 38 c5 aa  40 40 42 e9  93 
8d 10 58  66 46 b4 cd
Oct  4 09:34:03 zebedee pluto[27098]: |   2f 8b c9 d4  f3 d9 ff 26  46 
32 65 9d  8e 57 35 68
Oct  4 09:34:03 zebedee pluto[27098]: |   dd 25 76 8c  56 c0 56 5a  11 
24 92 2b  98 7c dc bd
Oct  4 09:34:03 zebedee pluto[27098]: |   54 73 26 5a  a1 81 87 95  a8 
a7 67 05  21 bd 6e 94
Oct  4 09:34:03 zebedee pluto[27098]: |   86 99 78 f8
Oct  4 09:34:03 zebedee pluto[27098]: | control:
Oct  4 09:34:03 zebedee pluto[27098]: |   18 00 00 00  00 00 00 00  08 
00 00 00  02 00 00 00
Oct  4 09:34:03 zebedee pluto[27098]: |   c0 a8 01 64  c0 a8 01 64  2c 
00 00 00  00 00 00 00
Oct  4 09:34:03 zebedee pluto[27098]: |   0b 00 00 00  6f 00 00 00  02 
03 03 00  00 00 00 00
Oct  4 09:34:03 zebedee pluto[27098]: |   00 00 00 00  02 00 00 00  c0 
a8 01 65  00 00 00 00
Oct  4 09:34:03 zebedee pluto[27098]: |   00 00 00 00
Oct  4 09:34:03 zebedee pluto[27098]: | name:
Oct  4 09:34:03 zebedee pluto[27098]: |   02 00 11 94  c0 a8 01 65  00 
00 00 00  00 00 00 00
Oct  4 09:34:03 zebedee pluto[27098]: ERROR: asynchronous network error 
report on eth0 (sport=4500) for message to 192.168.1.101 port 4500, 
complainant 192.168.1.101: Connection refused [errno 111, origin ICMP 
type 3 code 3 (not authenticated)]
Oct  4 09:34:03 zebedee pluto[27098]: | * processed 0 messages from 
cryptographic helpers
Oct  4 09:34:03 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 8 seconds
Oct  4 09:34:03 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 8 seconds
Oct  4 09:34:04 zebedee pluto[27098]: |
Oct  4 09:34:04 zebedee pluto[27098]: | rejected packet:
Oct  4 09:34:04 zebedee pluto[27098]: |   0b ac 53 d0  00 00 00 11  d6 
91 90 95  f2 a3 55 50
Oct  4 09:34:04 zebedee pluto[27098]: |   c7 55 3b d8  ea 53 c6 ff  5c 
a6 f1 10  b4 d7 52 ce
Oct  4 09:34:04 zebedee pluto[27098]: |   a4 a6 d3 69  80 fe 10 30  33 
f0 64 ba  6d d0 dd 84
Oct  4 09:34:04 zebedee pluto[27098]: |   e4 97 49 ae  83 fc 1b 2c  d1 
6e a8 bf  ed 5e e5 4f
Oct  4 09:34:04 zebedee pluto[27098]: |   c3 c3 8a 72  ef 54 3f 64  ad 
3e 86 2e  ed c8 d4 69
Oct  4 09:34:04 zebedee pluto[27098]: |   6c 4b 28 b2  f0 1f 72 7d  cc 
37 ce 02  dc 15 83 2d
Oct  4 09:34:04 zebedee pluto[27098]: |   94 ec 6e da  6d c3 a2 4e  31 
b6 5c 27  71 c0 c2 84
Oct  4 09:34:04 zebedee pluto[27098]: |   f6 49 b5 c0
Oct  4 09:34:04 zebedee pluto[27098]: | control:
Oct  4 09:34:04 zebedee pluto[27098]: |   18 00 00 00  00 00 00 00  08 
00 00 00  02 00 00 00
Oct  4 09:34:04 zebedee pluto[27098]: |   c0 a8 01 64  c0 a8 01 64  2c 
00 00 00  00 00 00 00
Oct  4 09:34:04 zebedee pluto[27098]: |   0b 00 00 00  6f 00 00 00  02 
03 03 00  00 00 00 00
Oct  4 09:34:04 zebedee pluto[27098]: |   00 00 00 00  02 00 00 00  c0 
a8 01 65  00 00 00 00
Oct  4 09:34:04 zebedee pluto[27098]: |   00 00 00 00
Oct  4 09:34:04 zebedee pluto[27098]: | name:
Oct  4 09:34:04 zebedee pluto[27098]: |   02 00 11 94  c0 a8 01 65  00 
00 00 00  00 00 00 00
Oct  4 09:34:04 zebedee pluto[27098]: ERROR: asynchronous network error 
report on eth0 (sport=4500) for message to 192.168.1.101 port 4500, 
complainant 192.168.1.101: Connection refused [errno 111, origin ICMP 
type 3 code 3 (not authenticated)]
Oct  4 09:34:04 zebedee pluto[27098]: | * processed 0 messages from 
cryptographic helpers
Oct  4 09:34:04 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 7 seconds
Oct  4 09:34:04 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 7 seconds
Oct  4 09:34:11 zebedee pluto[27098]: |
Oct  4 09:34:11 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 0 seconds
Oct  4 09:34:11 zebedee pluto[27098]: | *time to handle event
Oct  4 09:34:11 zebedee pluto[27098]: | handling event EVENT_NAT_T_KEEPALIVE
Oct  4 09:34:11 zebedee pluto[27098]: | event after this is 
EVENT_PENDING_DDNS in 40 seconds
Oct  4 09:34:11 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:34:11 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:34:11 zebedee pluto[27098]: | sending 1 bytes for NAT-T Keep 
Alive through eth0:4500 to 192.168.1.101:4500 (using #5)
Oct  4 09:34:11 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:34:11 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:34:11 zebedee pluto[27098]: | sending 1 bytes for NAT-T Keep 
Alive through eth0:4500 to 192.168.1.101:4500 (using #4)
Oct  4 09:34:11 zebedee pluto[27098]: | inserting event 
EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct  4 09:34:11 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 20 seconds
Oct  4 09:34:11 zebedee pluto[27098]: |
Oct  4 09:34:11 zebedee pluto[27098]: | rejected packet:
Oct  4 09:34:11 zebedee pluto[27098]: |   ff
Oct  4 09:34:11 zebedee pluto[27098]: | control:
Oct  4 09:34:11 zebedee pluto[27098]: |   18 00 00 00  00 00 00 00  08 
00 00 00  02 00 00 00
Oct  4 09:34:11 zebedee pluto[27098]: |   c0 a8 01 64  c0 a8 01 64  2c 
00 00 00  00 00 00 00
Oct  4 09:34:11 zebedee pluto[27098]: |   0b 00 00 00  6f 00 00 00  02 
03 03 00  00 00 00 00
Oct  4 09:34:11 zebedee pluto[27098]: |   00 00 00 00  02 00 00 00  c0 
a8 01 65  00 00 00 00
Oct  4 09:34:11 zebedee pluto[27098]: |   00 00 00 00
Oct  4 09:34:11 zebedee pluto[27098]: | name:
Oct  4 09:34:11 zebedee pluto[27098]: |   02 00 11 94  c0 a8 01 65  00 
00 00 00  00 00 00 00
Oct  4 09:34:11 zebedee pluto[27098]: | rejected packet:
Oct  4 09:34:11 zebedee pluto[27098]: |   ff
Oct  4 09:34:11 zebedee pluto[27098]: | control:
Oct  4 09:34:11 zebedee pluto[27098]: |   18 00 00 00  00 00 00 00  08 
00 00 00  02 00 00 00
Oct  4 09:34:11 zebedee pluto[27098]: |   c0 a8 01 64  c0 a8 01 64  2c 
00 00 00  00 00 00 00
Oct  4 09:34:11 zebedee pluto[27098]: |   0b 00 00 00  6f 00 00 00  02 
03 03 00  00 00 00 00
Oct  4 09:34:11 zebedee pluto[27098]: |   00 00 00 00  02 00 00 00  c0 
a8 01 65  00 00 00 00
Oct  4 09:34:11 zebedee pluto[27098]: |   00 00 00 00
Oct  4 09:34:11 zebedee pluto[27098]: | name:
Oct  4 09:34:11 zebedee pluto[27098]: |   02 00 11 94  c0 a8 01 65  00 
00 00 00  00 00 00 00
Oct  4 09:34:11 zebedee pluto[27098]: | * processed 0 messages from 
cryptographic helpers
Oct  4 09:34:11 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 20 seconds
Oct  4 09:34:11 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 20 seconds
Oct  4 09:34:31 zebedee pluto[27098]: |
Oct  4 09:34:31 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 0 seconds
Oct  4 09:34:31 zebedee pluto[27098]: | *time to handle event
Oct  4 09:34:31 zebedee pluto[27098]: | handling event EVENT_NAT_T_KEEPALIVE
Oct  4 09:34:31 zebedee pluto[27098]: | event after this is 
EVENT_PENDING_DDNS in 20 seconds
Oct  4 09:34:31 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:34:31 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:34:31 zebedee pluto[27098]: | sending 1 bytes for NAT-T Keep 
Alive through eth0:4500 to 192.168.1.101:4500 (using #5)
Oct  4 09:34:31 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:34:31 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:34:31 zebedee pluto[27098]: | sending 1 bytes for NAT-T Keep 
Alive through eth0:4500 to 192.168.1.101:4500 (using #4)
Oct  4 09:34:31 zebedee pluto[27098]: | inserting event 
EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct  4 09:34:31 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 20 seconds
Oct  4 09:34:31 zebedee pluto[27098]: |
Oct  4 09:34:31 zebedee pluto[27098]: | rejected packet:
Oct  4 09:34:31 zebedee pluto[27098]: |   ff
Oct  4 09:34:31 zebedee pluto[27098]: | control:
Oct  4 09:34:31 zebedee pluto[27098]: |   18 00 00 00  00 00 00 00  08 
00 00 00  02 00 00 00
Oct  4 09:34:31 zebedee pluto[27098]: |   c0 a8 01 64  c0 a8 01 64  2c 
00 00 00  00 00 00 00
Oct  4 09:34:31 zebedee pluto[27098]: |   0b 00 00 00  6f 00 00 00  02 
03 03 00  00 00 00 00
Oct  4 09:34:31 zebedee pluto[27098]: |   00 00 00 00  02 00 00 00  c0 
a8 01 65  00 00 00 00
Oct  4 09:34:31 zebedee pluto[27098]: |   00 00 00 00
Oct  4 09:34:31 zebedee pluto[27098]: | name:
Oct  4 09:34:31 zebedee pluto[27098]: |   02 00 11 94  c0 a8 01 65  00 
00 00 00  00 00 00 00
Oct  4 09:34:31 zebedee pluto[27098]: | rejected packet:
Oct  4 09:34:31 zebedee pluto[27098]: |   ff
Oct  4 09:34:31 zebedee pluto[27098]: | control:
Oct  4 09:34:31 zebedee pluto[27098]: |   18 00 00 00  00 00 00 00  08 
00 00 00  02 00 00 00
Oct  4 09:34:31 zebedee pluto[27098]: |   c0 a8 01 64  c0 a8 01 64  2c 
00 00 00  00 00 00 00
Oct  4 09:34:31 zebedee pluto[27098]: |   0b 00 00 00  6f 00 00 00  02 
03 03 00  00 00 00 00
Oct  4 09:34:31 zebedee pluto[27098]: |   00 00 00 00  02 00 00 00  c0 
a8 01 65  00 00 00 00
Oct  4 09:34:31 zebedee pluto[27098]: |   00 00 00 00
Oct  4 09:34:31 zebedee pluto[27098]: | name:
Oct  4 09:34:31 zebedee pluto[27098]: |   02 00 11 94  c0 a8 01 65  00 
00 00 00  00 00 00 00
Oct  4 09:34:31 zebedee pluto[27098]: | * processed 0 messages from 
cryptographic helpers
Oct  4 09:34:31 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 20 seconds
Oct  4 09:34:31 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 20 seconds
Oct  4 09:34:51 zebedee pluto[27098]: |
Oct  4 09:34:51 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 0 seconds
Oct  4 09:34:51 zebedee pluto[27098]: | *time to handle event
Oct  4 09:34:51 zebedee pluto[27098]: | handling event EVENT_NAT_T_KEEPALIVE
Oct  4 09:34:51 zebedee pluto[27098]: | event after this is 
EVENT_PENDING_DDNS in 0 seconds
Oct  4 09:34:51 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:34:51 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:34:51 zebedee pluto[27098]: | sending 1 bytes for NAT-T Keep 
Alive through eth0:4500 to 192.168.1.101:4500 (using #5)
Oct  4 09:34:51 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:34:51 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:34:51 zebedee pluto[27098]: | sending 1 bytes for NAT-T Keep 
Alive through eth0:4500 to 192.168.1.101:4500 (using #4)
Oct  4 09:34:51 zebedee pluto[27098]: | inserting event 
EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct  4 09:34:51 zebedee pluto[27098]: | handling event EVENT_PENDING_DDNS
Oct  4 09:34:51 zebedee pluto[27098]: | event after this is 
EVENT_NAT_T_KEEPALIVE in 20 seconds
Oct  4 09:34:51 zebedee pluto[27098]: | inserting event 
EVENT_PENDING_DDNS, timeout in 60 seconds
Oct  4 09:34:51 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 20 seconds
Oct  4 09:34:51 zebedee pluto[27098]: |
Oct  4 09:34:51 zebedee pluto[27098]: | rejected packet:
Oct  4 09:34:51 zebedee pluto[27098]: |   ff
Oct  4 09:34:51 zebedee pluto[27098]: | control:
Oct  4 09:34:51 zebedee pluto[27098]: |   18 00 00 00  00 00 00 00  08 
00 00 00  02 00 00 00
Oct  4 09:34:51 zebedee pluto[27098]: |   c0 a8 01 64  c0 a8 01 64  2c 
00 00 00  00 00 00 00
Oct  4 09:34:51 zebedee pluto[27098]: |   0b 00 00 00  6f 00 00 00  02 
03 03 00  00 00 00 00
Oct  4 09:34:51 zebedee pluto[27098]: |   00 00 00 00  02 00 00 00  c0 
a8 01 65  00 00 00 00
Oct  4 09:34:51 zebedee pluto[27098]: |   00 00 00 00
Oct  4 09:34:51 zebedee pluto[27098]: | name:
Oct  4 09:34:51 zebedee pluto[27098]: |   02 00 11 94  c0 a8 01 65  00 
00 00 00  00 00 00 00
Oct  4 09:34:51 zebedee pluto[27098]: | rejected packet:
Oct  4 09:34:51 zebedee pluto[27098]: |   ff
Oct  4 09:34:51 zebedee pluto[27098]: | control:
Oct  4 09:34:51 zebedee pluto[27098]: |   18 00 00 00  00 00 00 00  08 
00 00 00  02 00 00 00
Oct  4 09:34:51 zebedee pluto[27098]: |   c0 a8 01 64  c0 a8 01 64  2c 
00 00 00  00 00 00 00
Oct  4 09:34:51 zebedee pluto[27098]: |   0b 00 00 00  6f 00 00 00  02 
03 03 00  00 00 00 00
Oct  4 09:34:51 zebedee pluto[27098]: |   00 00 00 00  02 00 00 00  c0 
a8 01 65  00 00 00 00
Oct  4 09:34:51 zebedee pluto[27098]: |   00 00 00 00
Oct  4 09:34:51 zebedee pluto[27098]: | name:
Oct  4 09:34:51 zebedee pluto[27098]: |   02 00 11 94  c0 a8 01 65  00 
00 00 00  00 00 00 00
Oct  4 09:34:51 zebedee pluto[27098]: | * processed 0 messages from 
cryptographic helpers
Oct  4 09:34:51 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 20 seconds
Oct  4 09:34:51 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 20 seconds
Oct  4 09:35:07 zebedee sudo: testuser : TTY=pts/1 ; PWD=/home/testuser 
; USER=root ; COMMAND=/usr/bin/vi /etc/xl2tpd/xl2tpd.conf
Oct  4 09:35:11 zebedee pluto[27098]: |
Oct  4 09:35:11 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 0 seconds
Oct  4 09:35:11 zebedee pluto[27098]: | *time to handle event
Oct  4 09:35:11 zebedee pluto[27098]: | handling event EVENT_NAT_T_KEEPALIVE
Oct  4 09:35:11 zebedee pluto[27098]: | event after this is 
EVENT_PENDING_PHASE2 in 35 seconds
Oct  4 09:35:11 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:35:11 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:35:11 zebedee pluto[27098]: | sending 1 bytes for NAT-T Keep 
Alive through eth0:4500 to 192.168.1.101:4500 (using #5)
Oct  4 09:35:11 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:35:11 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:35:11 zebedee pluto[27098]: | sending 1 bytes for NAT-T Keep 
Alive through eth0:4500 to 192.168.1.101:4500 (using #4)
Oct  4 09:35:11 zebedee pluto[27098]: | inserting event 
EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct  4 09:35:11 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 20 seconds
Oct  4 09:35:12 zebedee pluto[27098]: |
Oct  4 09:35:12 zebedee pluto[27098]: | rejected packet:
Oct  4 09:35:12 zebedee pluto[27098]: |   ff
Oct  4 09:35:12 zebedee pluto[27098]: | control:
Oct  4 09:35:12 zebedee pluto[27098]: |   18 00 00 00  00 00 00 00  08 
00 00 00  02 00 00 00
Oct  4 09:35:12 zebedee pluto[27098]: |   c0 a8 01 64  c0 a8 01 64  2c 
00 00 00  00 00 00 00
Oct  4 09:35:12 zebedee pluto[27098]: |   0b 00 00 00  6f 00 00 00  02 
03 03 00  00 00 00 00
Oct  4 09:35:12 zebedee pluto[27098]: |   00 00 00 00  02 00 00 00  c0 
a8 01 65  00 00 00 00
Oct  4 09:35:12 zebedee pluto[27098]: |   00 00 00 00
Oct  4 09:35:12 zebedee pluto[27098]: | name:
Oct  4 09:35:12 zebedee pluto[27098]: |   02 00 11 94  c0 a8 01 65  00 
00 00 00  00 00 00 00
Oct  4 09:35:12 zebedee pluto[27098]: | rejected packet:
Oct  4 09:35:12 zebedee pluto[27098]: |   ff
Oct  4 09:35:12 zebedee pluto[27098]: | control:
Oct  4 09:35:12 zebedee pluto[27098]: |   18 00 00 00  00 00 00 00  08 
00 00 00  02 00 00 00
Oct  4 09:35:12 zebedee pluto[27098]: |   c0 a8 01 64  c0 a8 01 64  2c 
00 00 00  00 00 00 00
Oct  4 09:35:12 zebedee pluto[27098]: |   0b 00 00 00  6f 00 00 00  02 
03 03 00  00 00 00 00
Oct  4 09:35:12 zebedee pluto[27098]: |   00 00 00 00  02 00 00 00  c0 
a8 01 65  00 00 00 00
Oct  4 09:35:12 zebedee pluto[27098]: |   00 00 00 00
Oct  4 09:35:12 zebedee pluto[27098]: | name:
Oct  4 09:35:12 zebedee pluto[27098]: |   02 00 11 94  c0 a8 01 65  00 
00 00 00  00 00 00 00
Oct  4 09:35:12 zebedee pluto[27098]: | * processed 0 messages from 
cryptographic helpers
Oct  4 09:35:12 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 19 seconds
Oct  4 09:35:12 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 19 seconds
Oct  4 09:35:22 zebedee sudo: testuser : TTY=pts/1 ; PWD=/home/testuser 
; USER=root ; COMMAND=/usr/bin/nano /etc/ipsec.conf
Oct  4 09:35:31 zebedee pluto[27098]: |
Oct  4 09:35:31 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 0 seconds
Oct  4 09:35:31 zebedee pluto[27098]: | *time to handle event
Oct  4 09:35:31 zebedee pluto[27098]: | handling event EVENT_NAT_T_KEEPALIVE
Oct  4 09:35:31 zebedee pluto[27098]: | event after this is 
EVENT_PENDING_PHASE2 in 15 seconds
Oct  4 09:35:31 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:35:31 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:35:31 zebedee pluto[27098]: | sending 1 bytes for NAT-T Keep 
Alive through eth0:4500 to 192.168.1.101:4500 (using #5)
Oct  4 09:35:31 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:35:31 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:35:31 zebedee pluto[27098]: | sending 1 bytes for NAT-T Keep 
Alive through eth0:4500 to 192.168.1.101:4500 (using #4)
Oct  4 09:35:31 zebedee pluto[27098]: | inserting event 
EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct  4 09:35:31 zebedee pluto[27098]: | next event EVENT_PENDING_PHASE2 
in 15 seconds
Oct  4 09:35:31 zebedee pluto[27098]: |
Oct  4 09:35:31 zebedee pluto[27098]: | rejected packet:
Oct  4 09:35:31 zebedee pluto[27098]: |   ff
Oct  4 09:35:31 zebedee pluto[27098]: | control:
Oct  4 09:35:31 zebedee pluto[27098]: |   18 00 00 00  00 00 00 00  08 
00 00 00  02 00 00 00
Oct  4 09:35:31 zebedee pluto[27098]: |   c0 a8 01 64  c0 a8 01 64  2c 
00 00 00  00 00 00 00
Oct  4 09:35:31 zebedee pluto[27098]: |   0b 00 00 00  6f 00 00 00  02 
03 03 00  00 00 00 00
Oct  4 09:35:31 zebedee pluto[27098]: |   00 00 00 00  02 00 00 00  c0 
a8 01 65  00 00 00 00
Oct  4 09:35:31 zebedee pluto[27098]: |   00 00 00 00
Oct  4 09:35:31 zebedee pluto[27098]: | name:
Oct  4 09:35:31 zebedee pluto[27098]: |   02 00 11 94  c0 a8 01 65  00 
00 00 00  00 00 00 00
Oct  4 09:35:31 zebedee pluto[27098]: | rejected packet:
Oct  4 09:35:31 zebedee pluto[27098]: |   ff
Oct  4 09:35:31 zebedee pluto[27098]: | control:
Oct  4 09:35:31 zebedee pluto[27098]: |   18 00 00 00  00 00 00 00  08 
00 00 00  02 00 00 00
Oct  4 09:35:31 zebedee pluto[27098]: |   c0 a8 01 64  c0 a8 01 64  2c 
00 00 00  00 00 00 00
Oct  4 09:35:31 zebedee pluto[27098]: |   0b 00 00 00  6f 00 00 00  02 
03 03 00  00 00 00 00
Oct  4 09:35:31 zebedee pluto[27098]: |   00 00 00 00  02 00 00 00  c0 
a8 01 65  00 00 00 00
Oct  4 09:35:31 zebedee pluto[27098]: |   00 00 00 00
Oct  4 09:35:31 zebedee pluto[27098]: | name:
Oct  4 09:35:31 zebedee pluto[27098]: |   02 00 11 94  c0 a8 01 65  00 
00 00 00  00 00 00 00
Oct  4 09:35:31 zebedee pluto[27098]: | * processed 0 messages from 
cryptographic helpers
Oct  4 09:35:31 zebedee pluto[27098]: | next event EVENT_PENDING_PHASE2 
in 15 seconds
Oct  4 09:35:31 zebedee pluto[27098]: | next event EVENT_PENDING_PHASE2 
in 15 seconds
Oct  4 09:35:41 zebedee sudo: testuser : TTY=pts/1 ; PWD=/home/testuser 
; USER=root ; COMMAND=/usr/bin/vi /etc/xl2tpd/xl2tpd.conf
Oct  4 09:35:46 zebedee pluto[27098]: |
Oct  4 09:35:46 zebedee pluto[27098]: | next event EVENT_PENDING_PHASE2 
in 0 seconds
Oct  4 09:35:46 zebedee pluto[27098]: | *time to handle event
Oct  4 09:35:46 zebedee pluto[27098]: | handling event EVENT_PENDING_PHASE2
Oct  4 09:35:46 zebedee pluto[27098]: | event after this is 
EVENT_NAT_T_KEEPALIVE in 5 seconds
Oct  4 09:35:46 zebedee pluto[27098]: | inserting event 
EVENT_PENDING_PHASE2, timeout in 120 seconds
Oct  4 09:35:46 zebedee pluto[27098]: | pending review: connection 
"L2TP" was not up, skipped
Oct  4 09:35:46 zebedee pluto[27098]: | pending review: connection 
"L2TP" was not up, skipped
Oct  4 09:35:46 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 5 seconds
Oct  4 09:35:51 zebedee pluto[27098]: |
Oct  4 09:35:51 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 0 seconds
Oct  4 09:35:51 zebedee pluto[27098]: | *time to handle event
Oct  4 09:35:51 zebedee pluto[27098]: | handling event EVENT_NAT_T_KEEPALIVE
Oct  4 09:35:51 zebedee pluto[27098]: | event after this is 
EVENT_PENDING_DDNS in 0 seconds
Oct  4 09:35:51 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:35:51 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:35:51 zebedee pluto[27098]: | sending 1 bytes for NAT-T Keep 
Alive through eth0:4500 to 192.168.1.101:4500 (using #5)
Oct  4 09:35:51 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:35:51 zebedee pluto[27098]: | processing connection L2TP[4] 
192.168.1.101
Oct  4 09:35:51 zebedee pluto[27098]: | sending 1 bytes for NAT-T Keep 
Alive through eth0:4500 to 192.168.1.101:4500 (using #4)
Oct  4 09:35:51 zebedee pluto[27098]: | inserting event 
EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Oct  4 09:35:51 zebedee pluto[27098]: | handling event EVENT_PENDING_DDNS
Oct  4 09:35:51 zebedee pluto[27098]: | event after this is 
EVENT_NAT_T_KEEPALIVE in 20 seconds
Oct  4 09:35:51 zebedee pluto[27098]: | inserting event 
EVENT_PENDING_DDNS, timeout in 60 seconds
Oct  4 09:35:51 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 20 seconds
Oct  4 09:35:51 zebedee pluto[27098]: |
Oct  4 09:35:51 zebedee pluto[27098]: | rejected packet:
Oct  4 09:35:51 zebedee pluto[27098]: |   ff
Oct  4 09:35:51 zebedee pluto[27098]: | control:
Oct  4 09:35:51 zebedee pluto[27098]: |   18 00 00 00  00 00 00 00  08 
00 00 00  02 00 00 00
Oct  4 09:35:51 zebedee pluto[27098]: |   c0 a8 01 64  c0 a8 01 64  2c 
00 00 00  00 00 00 00
Oct  4 09:35:51 zebedee pluto[27098]: |   0b 00 00 00  6f 00 00 00  02 
03 03 00  00 00 00 00
Oct  4 09:35:51 zebedee pluto[27098]: |   00 00 00 00  02 00 00 00  c0 
a8 01 65  00 00 00 00
Oct  4 09:35:51 zebedee pluto[27098]: |   00 00 00 00
Oct  4 09:35:51 zebedee pluto[27098]: | name:
Oct  4 09:35:51 zebedee pluto[27098]: |   02 00 11 94  c0 a8 01 65  00 
00 00 00  00 00 00 00
Oct  4 09:35:51 zebedee pluto[27098]: | rejected packet:
Oct  4 09:35:51 zebedee pluto[27098]: |   ff
Oct  4 09:35:51 zebedee pluto[27098]: | control:
Oct  4 09:35:51 zebedee pluto[27098]: |   18 00 00 00  00 00 00 00  08 
00 00 00  02 00 00 00
Oct  4 09:35:51 zebedee pluto[27098]: |   c0 a8 01 64  c0 a8 01 64  2c 
00 00 00  00 00 00 00
Oct  4 09:35:51 zebedee pluto[27098]: |   0b 00 00 00  6f 00 00 00  02 
03 03 00  00 00 00 00
Oct  4 09:35:51 zebedee pluto[27098]: |   00 00 00 00  02 00 00 00  c0 
a8 01 65  00 00 00 00
Oct  4 09:35:51 zebedee pluto[27098]: |   00 00 00 00
Oct  4 09:35:51 zebedee pluto[27098]: | name:
Oct  4 09:35:51 zebedee pluto[27098]: |   02 00 11 94  c0 a8 01 65  00 
00 00 00  00 00 00 00
Oct  4 09:35:51 zebedee pluto[27098]: | * processed 0 messages from 
cryptographic helpers
Oct  4 09:35:51 zebedee pluto[27098]: | next event EVENT_NAT_T_KEEPALIVE 
in 20 seconds





More information about the Users mailing list