🚀 go-pugleaf

RetroBBS NetNews Server

Inspired by RockSolid Light RIP Retro Guy

Article View: pl.comp.networking
Article #278146

ipsec + l2tp vpn problem z uruchomieniem

#278146
From: Daniel Jaworski
Date: Wed, 20 Sep 2006 16:25
2934 lines
153133 bytes
Próbuję nawiązać szyfrowane połączeniem za pośrednictwem IPSec i L2TP 
pomiędzy WindowsemXP i Linuksem (Ubuntu z jądrem 2.6.15-27).

Wykonuję wszystko wg opisu ze strony 
http://www.jacco2.dds.nl/networking/freeswan-l2tp.html.

I nie mogę odpalić próbnego połączenia (zabezpieczonego hasłem).

Proszę o jakieś wskazówki, ponieważ skończyły mi się pomysły już...
Poniżej zamieszczam informacje o mojej konfiguracji.

Zainstalowałem Openswan (2.4.4) oraz L2TPD (0.70-pre20031121).

Serwer, z którym się próbuję łączyć ma adres 192.168.1.7. Klient -- 
192.168.1.250. Oczywiście normalna łączność między komputerami działa. 
"Po drodze" nie ma innych urządzeń niż przełącznik.

Konfiguracja:
#/etc/ipsec.conf
version 2.0     # conforms to second version of ipsec.conf specification

config setup
         plutodebug="all"

virtual_private=%v4:10.0.0.0/8,%v4:192.168.0.0/16,%4:172.16.0.0/12

conn L2TP-PSK
         authby=secret
         pfs=no
         rekey=no
         keyingtries=3
         left=192.168.1.7
         leftprotoport=17/1701
         right=192.168.1.250
         rightprotoport=17/%any
         auto=add

include /etc/ipsec.d/examples/no_oe.conf
#=====================================================================


#/etc/ipsec.secret
: RSA /etc/ipsec.d/private/djpcKey.pem

192.168.1.7 192.168.1.250: PSK "buba17"
#=====================================================================


;/etc/l2tp/l2tp.conf
lns default]                           ; Our fallthrough LNS definition
ip range = 192.168.1.128-192.168.2.154 ; * Allocate from this IP range
local ip = 192.168.1.99                ; * Our local IP to use
length bit = yes                       ; * Use length bit in payload?
equire chap = yes                      ; * Require CHAP auth. by peer
refuse pap = yes                       ; * Refuse PAP authentication
require authentication = yes           ; * Require peer to authenticate
name = linuxvpnserver                  ; * Report this as our hostname
ppp debug = yes                        ; * Turn on PPP debugging
ppoptfile = /etc/ppp/options.l2tpd     ; * ppp options file
;=====================================================================


#/etc/ppp/options.l2tpd
lock
noauth
debug
dump
logfd 2
logfile /var/log/l2tpd.log
nodetach
noccp
novj
novjccomp
nopcomp
noaccomp
#=====================================================================


#/etc/ppp/chap.secrets
# client        server  secret                  IP addresses
jacco           *       "mysecret"              192.168.1.0/24
*               jacco   "mysecret"              192.168.1.0/24
#=====================================================================

W kliencie załączona jest opcja "Użyj klucza wstępnego do 
uwierzytelniania", podany odpowiedni klucz.
Wymuszone jest użycie CHAP (zaznaczona tylko opcja CHAP na liście 
dostępnych protokołów).
Na liście "Typ wirtualnej sieci prywatnej (VPN)" oczywiście wybrane jest 
"Sieć VPN z protokołem L2TP IPSec", a w ustawieniach _wyłączone_ są 
rozszerzenia LCP, kompresja programowa i negocjacja łącz wielokrotnych 
dla połączeń pojedynczych.

Załączam tu logi (/var/log/auth.log) oraz zrzut tcpdumpa.

$ sudo tcpdump -vv -i eth0 host 192.168.1.250
tcpdump: listening on eth0, link-type EN10MB (Ethernet), capture size 96 
bytes
18:21:57.552466 IP (tos 0x0, ttl 128, id 11919, offset 0, flags [none], 
proto: UDP (17), length: 340) 192.168.1.250.isakmp > 192.168.1.7.isakmp: 
isakmp 1.0 msgid  cookie ->: phase 1 I ident: [|sa]
18:21:58.787980 IP (tos 0x0, ttl  64, id 0, offset 0, flags [DF], proto: 
UDP (17), length: 148) 192.168.1.7.isakmp > 192.168.1.250.isakmp: isakmp 
1.0 msgid  cookie ->: phase 1 R ident: [|sa]
18:21:59.075765 IP (tos 0x0, ttl 128, id 11920, offset 0, flags [none], 
proto: UDP (17), length: 340) 192.168.1.250.isakmp > 192.168.1.7.isakmp: 
isakmp 1.0 msgid  cookie ->: phase 1 I ident: [|ke]
18:21:59.855308 IP (tos 0x0, ttl 128, id 11921, offset 0, flags [none], 
proto: UDP (17), length: 340) 192.168.1.250.isakmp > 192.168.1.7.isakmp: 
isakmp 1.0 msgid  cookie ->: phase 1 I ident: [|ke]
18:22:00.912866 IP (tos 0x0, ttl  64, id 0, offset 0, flags [DF], proto: 
UDP (17), length: 336) 192.168.1.7.isakmp > 192.168.1.250.isakmp: isakmp 
1.0 msgid  cookie ->: phase 1 R ident: [|ke]
18:22:01.013493 IP (tos 0x0, ttl 128, id 11922, offset 0, flags [none], 
proto: UDP (17), length: 96) 192.168.1.250.isakmp > 192.168.1.7.isakmp: 
isakmp 1.0 msgid  cookie ->: phase 1 I ident[E]: [encrypted id]
18:22:01.858300 IP (tos 0x0, ttl 128, id 11923, offset 0, flags [none], 
proto: UDP (17), length: 96) 192.168.1.250.isakmp > 192.168.1.7.isakmp: 
isakmp 1.0 msgid  cookie ->: phase 1 I ident[E]: [encrypted id]
18:22:02.216158 IP (tos 0x0, ttl  64, id 0, offset 0, flags [DF], proto: 
UDP (17), length: 96) 192.168.1.7.isakmp > 192.168.1.250.isakmp: isakmp 
1.0 msgid  cookie ->: phase 1 R ident[E]: [encrypted id]
18:22:02.218365 IP (tos 0x0, ttl 128, id 11924, offset 0, flags [none], 
proto: UDP (17), length: 1328) 192.168.1.250.isakmp > 
192.168.1.7.isakmp: isakmp 1.0 msgid  cookie ->: phase 2/others I 
oakley-quick[E]: [encrypted hash]
18:22:02.628152 IP (tos 0x0, ttl  64, id 0, offset 0, flags [DF], proto: 
UDP (17), length: 96) 192.168.1.7.isakmp > 192.168.1.250.isakmp: isakmp 
1.0 msgid  cookie ->: phase 1 R ident[E]: [encrypted id]
18:22:02.860085 IP (tos 0x0, ttl 128, id 11925, offset 0, flags [none], 
proto: UDP (17), length: 1328) 192.168.1.250.isakmp > 
192.168.1.7.isakmp: isakmp 1.0 msgid  cookie ->: phase 2/others I 
oakley-quick[E]: [encrypted hash]
18:22:03.787674 arp who-has 192.168.1.250 tell 192.168.1.7
18:22:03.788095 arp reply 192.168.1.250 is-at 00:d0:59:da:71:a9 (oui 
Unknown)
18:22:04.863157 IP (tos 0x0, ttl 128, id 11926, offset 0, flags [none], 
proto: UDP (17), length: 1328) 192.168.1.250.isakmp > 
192.168.1.7.isakmp: isakmp 1.0 msgid  cookie ->: phase 2/others I 
oakley-quick[E]: [encrypted hash]
18:22:08.869275 IP (tos 0x0, ttl 128, id 11927, offset 0, flags [none], 
proto: UDP (17), length: 1328) 192.168.1.250.isakmp > 
192.168.1.7.isakmp: isakmp 1.0 msgid  cookie ->: phase 2/others I 
oakley-quick[E]: [encrypted hash]
18:22:08.869316 IP (tos 0xc0, ttl  64, id 10350, offset 0, flags [none], 
proto: ICMP (1), length: 576) 192.168.1.7 > 192.168.1.250: ICMP 
192.168.1.7 udp port isakmp unreachable, length 556
         IP (tos 0x0, ttl 128, id 11927, offset 0, flags [none], proto: 
UDP (17), length: 1328) 192.168.1.250.isakmp > 192.168.1.7.isakmp: 
[|isakmp][|icmp]
18:22:16.881491 IP (tos 0x0, ttl 128, id 11930, offset 0, flags [none], 
proto: UDP (17), length: 1328) 192.168.1.250.isakmp > 
192.168.1.7.isakmp: isakmp 1.0 msgid  cookie ->: phase 2/others I 
oakley-quick[E]: [encrypted hash]
18:22:16.881535 IP (tos 0xc0, ttl  64, id 10351, offset 0, flags [none], 
proto: ICMP (1), length: 576) 192.168.1.7 > 192.168.1.250: ICMP 
192.168.1.7 udp port isakmp unreachable, length 556
         IP (tos 0x0, ttl 128, id 11930, offset 0, flags [none], proto: 
UDP (17), length: 1328) 192.168.1.250.isakmp > 192.168.1.7.isakmp: 
[|isakmp][|icmp]
18:22:32.905937 IP (tos 0x0, ttl 128, id 11933, offset 0, flags [none], 
proto: UDP (17), length: 1328) 192.168.1.250.isakmp > 
192.168.1.7.isakmp: isakmp 1.0 msgid  cookie ->: phase 2/others I 
oakley-quick[E]: [encrypted hash]
18:23:05.034795 IP (tos 0x0, ttl 128, id 11938, offset 0, flags [none], 
proto: UDP (17), length: 112) 192.168.1.250.isakmp > 192.168.1.7.isakmp: 
isakmp 1.0 msgid  cookie ->: phase 2/others I inf[E]: [encrypted hash]

20 packets captured
40 packets received by filter
0 packets dropped by kernel


Sep 20 18:11:46 djpc pluto[9618]: |
Sep 20 18:11:46 djpc pluto[9618]: | *received 312 bytes from 
192.168.1.250:500 on eth0 (port=500)
Sep 20 18:11:46 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46  00 00 00 
00  00 00 00 00
Sep 20 18:11:46 djpc pluto[9618]: |   01 10 02 00  00 00 00 00  00 00 01 
38  0d 00 00 c8
Sep 20 18:11:46 djpc pluto[9618]: |   00 00 00 01  00 00 00 01  00 00 00 
bc  01 01 00 05
Sep 20 18:11:46 djpc pluto[9618]: |   03 00 00 24  01 01 00 00  80 01 00 
05  80 02 00 02
Sep 20 18:11:46 djpc pluto[9618]: |   80 04 00 0e  80 03 00 01  80 0b 00 
01  00 0c 00 04
Sep 20 18:11:46 djpc pluto[9618]: |   00 00 70 80  03 00 00 24  02 01 00 
00  80 01 00 05
Sep 20 18:11:46 djpc pluto[9618]: |   80 02 00 02  80 04 00 02  80 03 00 
01  80 0b 00 01
Sep 20 18:11:46 djpc pluto[9618]: |   00 0c 00 04  00 00 70 80  03 00 00 
24  03 01 00 00
Sep 20 18:11:46 djpc pluto[9618]: |   80 01 00 05  80 02 00 01  80 04 00 
02  80 03 00 01
Sep 20 18:11:46 djpc pluto[9618]: |   80 0b 00 01  00 0c 00 04  00 00 70 
80  03 00 00 24
Sep 20 18:11:46 djpc pluto[9618]: |   04 01 00 00  80 01 00 01  80 02 00 
02  80 04 00 01
Sep 20 18:11:46 djpc pluto[9618]: |   80 03 00 01  80 0b 00 01  00 0c 00 
04  00 00 70 80
Sep 20 18:11:46 djpc pluto[9618]: |   00 00 00 24  05 01 00 00  80 01 00 
01  80 02 00 01
Sep 20 18:11:46 djpc pluto[9618]: |   80 04 00 01  80 03 00 01  80 0b 00 
01  00 0c 00 04
Sep 20 18:11:46 djpc pluto[9618]: |   00 00 70 80  0d 00 00 18  1e 2b 51 
69  05 99 1c 7d
Sep 20 18:11:46 djpc pluto[9618]: |   7c 96 fc bf  b5 87 e4 61  00 00 00 
04  0d 00 00 14
Sep 20 18:11:46 djpc pluto[9618]: |   40 48 b7 d5  6e bc e8 85  25 e7 de 
7f  00 d6 c2 d3
Sep 20 18:11:46 djpc pluto[9618]: |   0d 00 00 14  90 cb 80 91  3e bb 69 
6e  08 63 81 b5
Sep 20 18:11:46 djpc pluto[9618]: |   ec 42 7b 1f  00 00 00 14  26 24 4d 
38  ed db 61 b3
Sep 20 18:11:46 djpc pluto[9618]: |   17 2a 36 e3  d0 cf b8 19
Sep 20 18:11:46 djpc pluto[9618]: | **parse ISAKMP Message:
Sep 20 18:11:46 djpc pluto[9618]: |    initiator cookie:
Sep 20 18:11:46 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:46 djpc pluto[9618]: |    responder cookie:
Sep 20 18:11:46 djpc pluto[9618]: |   00 00 00 00  00 00 00 00
Sep 20 18:11:46 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_SA
Sep 20 18:11:46 djpc pluto[9618]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:11:46 djpc pluto[9618]: |    exchange type: ISAKMP_XCHG_IDPROT
Sep 20 18:11:46 djpc pluto[9618]: |    flags: none
Sep 20 18:11:46 djpc pluto[9618]: |    message ID:  00 00 00 00
Sep 20 18:11:46 djpc pluto[9618]: |    length: 312
Sep 20 18:11:46 djpc pluto[9618]: |  processing packet with exchange 
type=ISAKMP_XCHG_IDPROT (2)
Sep 20 18:11:46 djpc pluto[9618]: | ***parse ISAKMP Security Association 
Payload:
Sep 20 18:11:46 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_VID
Sep 20 18:11:46 djpc pluto[9618]: |    length: 200
Sep 20 18:11:46 djpc pluto[9618]: |    DOI: ISAKMP_DOI_IPSEC
Sep 20 18:11:46 djpc pluto[9618]: | ***parse ISAKMP Vendor ID Payload:
Sep 20 18:11:46 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_VID
Sep 20 18:11:46 djpc pluto[9618]: |    length: 24
Sep 20 18:11:46 djpc pluto[9618]: | ***parse ISAKMP Vendor ID Payload:
Sep 20 18:11:46 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_VID
Sep 20 18:11:46 djpc pluto[9618]: |    length: 20
Sep 20 18:11:46 djpc pluto[9618]: | ***parse ISAKMP Vendor ID Payload:
Sep 20 18:11:46 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_VID
Sep 20 18:11:46 djpc pluto[9618]: |    length: 20
Sep 20 18:11:46 djpc pluto[9618]: | ***parse ISAKMP Vendor ID Payload:
Sep 20 18:11:46 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:11:46 djpc pluto[9618]: |    length: 20
Sep 20 18:11:46 djpc pluto[9618]: packet from 192.168.1.250:500: 
ignoring Vendor ID payload [MS NT5 ISAKMPOAKLEY 00000004]
Sep 20 18:11:46 djpc pluto[9618]: packet from 192.168.1.250:500: 
ignoring Vendor ID payload [FRAGMENTATION]
Sep 20 18:11:46 djpc pluto[9618]: packet from 192.168.1.250:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] meth=106, 
but port floating is off
Sep 20 18:11:46 djpc pluto[9618]: packet from 192.168.1.250:500: 
ignoring Vendor ID payload [Vid-Initial-Contact]
Sep 20 18:11:46 djpc pluto[9618]: | find_host_connection called from 
main_inI1_outR1
Sep 20 18:11:46 djpc pluto[9618]: | find_host_pair: comparing to 
192.168.1.7:500 192.168.1.250:500
Sep 20 18:11:46 djpc pluto[9618]: | find_host_pair_conn 
(find_host_connection2): 192.168.1.7:500 192.168.1.250:500 -> hp:L2TP-PSK
Sep 20 18:11:46 djpc pluto[9618]: | creating state object #1 at 0x80fc910
Sep 20 18:11:46 djpc pluto[9618]: | processing connection L2TP-PSK
Sep 20 18:11:46 djpc pluto[9618]: | ICOOKIE:  a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:46 djpc pluto[9618]: | RCOOKIE:  8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:46 djpc pluto[9618]: | peer:  c0 a8 01 fa
Sep 20 18:11:46 djpc pluto[9618]: | state hash entry 0
Sep 20 18:11:46 djpc pluto[9618]: | inserting event EVENT_SO_DISCARD, 
timeout in 0 seconds for #1
Sep 20 18:11:46 djpc pluto[9618]: "L2TP-PSK" #1: responding to Main Mode
Sep 20 18:11:46 djpc pluto[9618]: | **emit ISAKMP Message:
Sep 20 18:11:46 djpc pluto[9618]: |    initiator cookie:
Sep 20 18:11:46 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:46 djpc pluto[9618]: |    responder cookie:
Sep 20 18:11:46 djpc pluto[9618]: |   8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:46 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_SA
Sep 20 18:11:46 djpc pluto[9618]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:11:46 djpc pluto[9618]: |    exchange type: ISAKMP_XCHG_IDPROT
Sep 20 18:11:47 djpc pluto[9618]: |    flags: none
Sep 20 18:11:47 djpc pluto[9618]: |    message ID:  00 00 00 00
Sep 20 18:11:47 djpc pluto[9618]: | ***emit ISAKMP Security Association 
Payload:
Sep 20 18:11:47 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_VID
Sep 20 18:11:47 djpc pluto[9618]: |    DOI: ISAKMP_DOI_IPSEC
Sep 20 18:11:47 djpc pluto[9618]: | ****parse IPsec DOI SIT:
Sep 20 18:11:47 djpc pluto[9618]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Sep 20 18:11:47 djpc pluto[9618]: | ****parse ISAKMP Proposal Payload:
Sep 20 18:11:47 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:11:47 djpc pluto[9618]: |    length: 188
Sep 20 18:11:47 djpc pluto[9618]: |    proposal number: 1
Sep 20 18:11:47 djpc pluto[9618]: |    protocol ID: PROTO_ISAKMP
Sep 20 18:11:47 djpc pluto[9618]: |    SPI size: 0
Sep 20 18:11:47 djpc pluto[9618]: |    number of transforms: 5
Sep 20 18:11:47 djpc pluto[9618]: | *****parse ISAKMP Transform Payload 
(ISAKMP):
Sep 20 18:11:47 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_T
Sep 20 18:11:47 djpc pluto[9618]: |    length: 36
Sep 20 18:11:47 djpc pluto[9618]: |    transform number: 1
Sep 20 18:11:47 djpc pluto[9618]: |    transform ID: KEY_IKE
Sep 20 18:11:47 djpc pluto[9618]: | ******parse ISAKMP Oakley attribute:
Sep 20 18:11:47 djpc pluto[9618]: |    af+type: OAKLEY_ENCRYPTION_ALGORITHM
Sep 20 18:11:47 djpc pluto[9618]: |    length/value: 5
Sep 20 18:11:47 djpc pluto[9618]: |    [5 is OAKLEY_3DES_CBC]
Sep 20 18:11:47 djpc pluto[9618]: | ike_alg_enc_ok(ealg=5,key_len=0): 
blocksize=8, keyminlen=192, keydeflen=192, keymaxlen=192, ret=1
Sep 20 18:11:47 djpc pluto[9618]: | ******parse ISAKMP Oakley attribute:
Sep 20 18:11:47 djpc pluto[9618]: |    af+type: OAKLEY_HASH_ALGORITHM
Sep 20 18:11:47 djpc pluto[9618]: |    length/value: 2
Sep 20 18:11:47 djpc pluto[9618]: |    [2 is OAKLEY_SHA1]
Sep 20 18:11:47 djpc pluto[9618]: | ******parse ISAKMP Oakley attribute:
Sep 20 18:11:47 djpc pluto[9618]: |    af+type: OAKLEY_GROUP_DESCRIPTION
Sep 20 18:11:47 djpc pluto[9618]: |    length/value: 14
Sep 20 18:11:47 djpc pluto[9618]: |    [14 is OAKLEY_GROUP_MODP2048]
Sep 20 18:11:47 djpc pluto[9618]: | ******parse ISAKMP Oakley attribute:
Sep 20 18:11:47 djpc pluto[9618]: |    af+type: OAKLEY_AUTHENTICATION_METHOD
Sep 20 18:11:47 djpc pluto[9618]: |    length/value: 1
Sep 20 18:11:47 djpc pluto[9618]: |    [1 is OAKLEY_PRESHARED_KEY]
Sep 20 18:11:47 djpc pluto[9618]: | started looking for secret for 
192.168.1.7->192.168.1.250 of kind PPK_PSK
Sep 20 18:11:47 djpc pluto[9618]: | actually looking for secret for 
192.168.1.7->192.168.1.250 of kind PPK_PSK
Sep 20 18:11:47 djpc pluto[9618]: | 1: compared PSK 192.168.1.250 to 
192.168.1.7 / 192.168.1.250 -> 2
Sep 20 18:11:47 djpc pluto[9618]: | 2: compared PSK 192.168.1.7 to 
192.168.1.7 / 192.168.1.250 -> 6
Sep 20 18:11:47 djpc pluto[9618]: | best_match 0>6 best=0x80fc1c8 (line=11)
Sep 20 18:11:47 djpc pluto[9618]: | concluding with best_match=6 
best=0x80fc1c8 (lineno=11)
Sep 20 18:11:47 djpc pluto[9618]: | ******parse ISAKMP Oakley attribute:
Sep 20 18:11:47 djpc pluto[9618]: |    af+type: OAKLEY_LIFE_TYPE
Sep 20 18:11:47 djpc pluto[9618]: |    length/value: 1
Sep 20 18:11:47 djpc pluto[9618]: |    [1 is OAKLEY_LIFE_SECONDS]
Sep 20 18:11:47 djpc pluto[9618]: | ******parse ISAKMP Oakley attribute:
Sep 20 18:11:47 djpc pluto[9618]: |    af+type: OAKLEY_LIFE_DURATION 
(variable length)
Sep 20 18:11:47 djpc pluto[9618]: |    length/value: 4
Sep 20 18:11:47 djpc pluto[9618]: |    long duration: 28800
Sep 20 18:11:47 djpc pluto[9618]: | Oakley Transform 1 accepted
Sep 20 18:11:47 djpc pluto[9618]: | ****emit IPsec DOI SIT:
Sep 20 18:11:47 djpc pluto[9618]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Sep 20 18:11:47 djpc pluto[9618]: | ****emit ISAKMP Proposal Payload:
Sep 20 18:11:47 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:11:47 djpc pluto[9618]: |    proposal number: 1
Sep 20 18:11:47 djpc pluto[9618]: |    protocol ID: PROTO_ISAKMP
Sep 20 18:11:47 djpc pluto[9618]: |    SPI size: 0
Sep 20 18:11:47 djpc pluto[9618]: |    number of transforms: 1
Sep 20 18:11:47 djpc pluto[9618]: | *****emit ISAKMP Transform Payload 
(ISAKMP):
Sep 20 18:11:47 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:11:47 djpc pluto[9618]: |    transform number: 1
Sep 20 18:11:47 djpc pluto[9618]: |    transform ID: KEY_IKE
Sep 20 18:11:47 djpc pluto[9618]: | emitting 28 raw bytes of attributes 
into ISAKMP Transform Payload (ISAKMP)
Sep 20 18:11:47 djpc pluto[9618]: | attributes  80 01 00 05  80 02 00 02 
  80 04 00 0e  80 03 00 01
Sep 20 18:11:47 djpc pluto[9618]: |   80 0b 00 01  00 0c 00 04  00 00 70 80
Sep 20 18:11:47 djpc pluto[9618]: | emitting length of ISAKMP Transform 
Payload (ISAKMP): 36
Sep 20 18:11:47 djpc pluto[9618]: | emitting length of ISAKMP Proposal 
Payload: 44
Sep 20 18:11:47 djpc pluto[9618]: | emitting length of ISAKMP Security 
Association Payload: 56
Sep 20 18:11:47 djpc pluto[9618]: | ***emit ISAKMP Vendor ID Payload:
Sep 20 18:11:47 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_VID
Sep 20 18:11:47 djpc pluto[9618]: | emitting 12 raw bytes of Vendor ID 
into ISAKMP Vendor ID Payload
Sep 20 18:11:47 djpc pluto[9618]: | Vendor ID  4f 45 7a 7d  46 46 46 66 
  67 72 5f 65
Sep 20 18:11:47 djpc pluto[9618]: | emitting length of ISAKMP Vendor ID 
Payload: 16
Sep 20 18:11:47 djpc pluto[9618]: | ***emit ISAKMP Vendor ID Payload:
Sep 20 18:11:47 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:11:47 djpc pluto[9618]: | emitting 16 raw bytes of DPP Vendor 
ID into ISAKMP Vendor ID Payload
Sep 20 18:11:47 djpc pluto[9618]: | DPP Vendor ID  af ca d7 13  68 a1 f1 
c9  6b 86 96 fc  77 57 01 00
Sep 20 18:11:47 djpc pluto[9618]: | emitting length of ISAKMP Vendor ID 
Payload: 20
Sep 20 18:11:47 djpc pluto[9618]: | sender checking NAT-t: 0 and 0
Sep 20 18:11:47 djpc pluto[9618]: | emitting length of ISAKMP Message: 120
Sep 20 18:11:47 djpc pluto[9618]: | complete state transition with STF_OK
Sep 20 18:11:47 djpc pluto[9618]: "L2TP-PSK" #1: transition from state 
STATE_MAIN_R0 to state STATE_MAIN_R1
Sep 20 18:11:47 djpc pluto[9618]: | sending reply packet to 
192.168.1.250:500 (from port=500)
Sep 20 18:11:47 djpc pluto[9618]: | sending 120 bytes for STATE_MAIN_R0 
through eth0:500 to 192.168.1.250:500:
Sep 20 18:11:47 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46  8d 38 1b 
33  f4 c5 e0 f4
Sep 20 18:11:47 djpc pluto[9618]: |   01 10 02 00  00 00 00 00  00 00 00 
78  0d 00 00 38
Sep 20 18:11:47 djpc pluto[9618]: |   00 00 00 01  00 00 00 01  00 00 00 
2c  01 01 00 01
Sep 20 18:11:47 djpc pluto[9618]: |   00 00 00 24  01 01 00 00  80 01 00 
05  80 02 00 02
Sep 20 18:11:47 djpc pluto[9618]: |   80 04 00 0e  80 03 00 01  80 0b 00 
01  00 0c 00 04
Sep 20 18:11:47 djpc pluto[9618]: |   00 00 70 80  0d 00 00 10  4f 45 7a 
7d  46 46 46 66
Sep 20 18:11:47 djpc pluto[9618]: |   67 72 5f 65  00 00 00 14  af ca d7 
13  68 a1 f1 c9
Sep 20 18:11:47 djpc pluto[9618]: |   6b 86 96 fc  77 57 01 00
Sep 20 18:11:47 djpc pluto[9618]: | inserting event EVENT_RETRANSMIT, 
timeout in 10 seconds for #1
Sep 20 18:11:47 djpc pluto[9618]: "L2TP-PSK" #1: STATE_MAIN_R1: sent 
MR1, expecting MI2
Sep 20 18:11:47 djpc pluto[9618]: | modecfg pull: noquirk policy:push 
not-client
Sep 20 18:11:47 djpc pluto[9618]: | phase 1 is done, looking for phase 1 
to unpend
Sep 20 18:11:47 djpc pluto[9618]: | next event EVENT_RETRANSMIT in 10 
seconds for #1
Sep 20 18:11:47 djpc pluto[9618]: |
Sep 20 18:11:47 djpc pluto[9618]: | *received 312 bytes from 
192.168.1.250:500 on eth0 (port=500)
Sep 20 18:11:47 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46  00 00 00 
00  00 00 00 00
Sep 20 18:11:48 djpc pluto[9618]: |   01 10 02 00  00 00 00 00  00 00 01 
38  0d 00 00 c8
Sep 20 18:11:48 djpc pluto[9618]: |   00 00 00 01  00 00 00 01  00 00 00 
bc  01 01 00 05
Sep 20 18:11:48 djpc pluto[9618]: |   03 00 00 24  01 01 00 00  80 01 00 
05  80 02 00 02
Sep 20 18:11:48 djpc pluto[9618]: |   80 04 00 0e  80 03 00 01  80 0b 00 
01  00 0c 00 04
Sep 20 18:11:48 djpc pluto[9618]: |   00 00 70 80  03 00 00 24  02 01 00 
00  80 01 00 05
Sep 20 18:11:48 djpc pluto[9618]: |   80 02 00 02  80 04 00 02  80 03 00 
01  80 0b 00 01
Sep 20 18:11:48 djpc pluto[9618]: |   00 0c 00 04  00 00 70 80  03 00 00 
24  03 01 00 00
Sep 20 18:11:48 djpc pluto[9618]: |   80 01 00 05  80 02 00 01  80 04 00 
02  80 03 00 01
Sep 20 18:11:48 djpc pluto[9618]: |   80 0b 00 01  00 0c 00 04  00 00 70 
80  03 00 00 24
Sep 20 18:11:48 djpc pluto[9618]: |   04 01 00 00  80 01 00 01  80 02 00 
02  80 04 00 01
Sep 20 18:11:48 djpc pluto[9618]: |   80 03 00 01  80 0b 00 01  00 0c 00 
04  00 00 70 80
Sep 20 18:11:48 djpc pluto[9618]: |   00 00 00 24  05 01 00 00  80 01 00 
01  80 02 00 01
Sep 20 18:11:48 djpc pluto[9618]: |   80 04 00 01  80 03 00 01  80 0b 00 
01  00 0c 00 04
Sep 20 18:11:48 djpc pluto[9618]: |   00 00 70 80  0d 00 00 18  1e 2b 51 
69  05 99 1c 7d
Sep 20 18:11:48 djpc pluto[9618]: |   7c 96 fc bf  b5 87 e4 61  00 00 00 
04  0d 00 00 14
Sep 20 18:11:48 djpc pluto[9618]: |   40 48 b7 d5  6e bc e8 85  25 e7 de 
7f  00 d6 c2 d3
Sep 20 18:11:48 djpc pluto[9618]: |   0d 00 00 14  90 cb 80 91  3e bb 69 
6e  08 63 81 b5
Sep 20 18:11:48 djpc pluto[9618]: |   ec 42 7b 1f  00 00 00 14  26 24 4d 
38  ed db 61 b3
Sep 20 18:11:48 djpc pluto[9618]: |   17 2a 36 e3  d0 cf b8 19
Sep 20 18:11:48 djpc pluto[9618]: | **parse ISAKMP Message:
Sep 20 18:11:48 djpc pluto[9618]: |    initiator cookie:
Sep 20 18:11:48 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:48 djpc pluto[9618]: |    responder cookie:
Sep 20 18:11:48 djpc pluto[9618]: |   00 00 00 00  00 00 00 00
Sep 20 18:11:48 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_SA
Sep 20 18:11:48 djpc pluto[9618]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:11:48 djpc pluto[9618]: |    exchange type: ISAKMP_XCHG_IDPROT
Sep 20 18:11:48 djpc pluto[9618]: |    flags: none
Sep 20 18:11:48 djpc pluto[9618]: |    message ID:  00 00 00 00
Sep 20 18:11:48 djpc pluto[9618]: |    length: 312
Sep 20 18:11:48 djpc pluto[9618]: |  processing packet with exchange 
type=ISAKMP_XCHG_IDPROT (2)
Sep 20 18:11:48 djpc pluto[9618]: | ***parse ISAKMP Security Association 
Payload:
Sep 20 18:11:48 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_VID
Sep 20 18:11:48 djpc pluto[9618]: |    length: 200
Sep 20 18:11:48 djpc pluto[9618]: |    DOI: ISAKMP_DOI_IPSEC
Sep 20 18:11:48 djpc pluto[9618]: | ***parse ISAKMP Vendor ID Payload:
Sep 20 18:11:48 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_VID
Sep 20 18:11:48 djpc pluto[9618]: |    length: 24
Sep 20 18:11:48 djpc pluto[9618]: | ***parse ISAKMP Vendor ID Payload:
Sep 20 18:11:48 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_VID
Sep 20 18:11:48 djpc pluto[9618]: |    length: 20
Sep 20 18:11:48 djpc pluto[9618]: | ***parse ISAKMP Vendor ID Payload:
Sep 20 18:11:48 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_VID
Sep 20 18:11:48 djpc pluto[9618]: |    length: 20
Sep 20 18:11:48 djpc pluto[9618]: | ***parse ISAKMP Vendor ID Payload:
Sep 20 18:11:48 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:11:48 djpc pluto[9618]: |    length: 20
Sep 20 18:11:48 djpc pluto[9618]: packet from 192.168.1.250:500: 
ignoring Vendor ID payload [MS NT5 ISAKMPOAKLEY 00000004]
Sep 20 18:11:48 djpc pluto[9618]: packet from 192.168.1.250:500: 
ignoring Vendor ID payload [FRAGMENTATION]
Sep 20 18:11:48 djpc pluto[9618]: packet from 192.168.1.250:500: 
received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n] meth=106, 
but port floating is off
Sep 20 18:11:48 djpc pluto[9618]: packet from 192.168.1.250:500: 
ignoring Vendor ID payload [Vid-Initial-Contact]
Sep 20 18:11:48 djpc pluto[9618]: | find_host_connection called from 
main_inI1_outR1
Sep 20 18:11:48 djpc pluto[9618]: | find_host_pair: comparing to 
192.168.1.7:500 192.168.1.250:500
Sep 20 18:11:48 djpc pluto[9618]: | find_host_pair_conn 
(find_host_connection2): 192.168.1.7:500 192.168.1.250:500 -> hp:L2TP-PSK
Sep 20 18:11:48 djpc pluto[9618]: | creating state object #2 at 0x80fcf40
Sep 20 18:11:48 djpc pluto[9618]: | processing connection L2TP-PSK
Sep 20 18:11:48 djpc pluto[9618]: | ICOOKIE:  a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:48 djpc pluto[9618]: | RCOOKIE:  c0 26 6e bf  f9 e0 f1 20
Sep 20 18:11:48 djpc pluto[9618]: | peer:  c0 a8 01 fa
Sep 20 18:11:48 djpc pluto[9618]: | state hash entry 5
Sep 20 18:11:48 djpc pluto[9618]: | inserting event EVENT_SO_DISCARD, 
timeout in 0 seconds for #2
Sep 20 18:11:48 djpc pluto[9618]: "L2TP-PSK" #2: responding to Main Mode
Sep 20 18:11:48 djpc pluto[9618]: | **emit ISAKMP Message:
Sep 20 18:11:48 djpc pluto[9618]: |    initiator cookie:
Sep 20 18:11:48 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:48 djpc pluto[9618]: |    responder cookie:
Sep 20 18:11:48 djpc pluto[9618]: |   c0 26 6e bf  f9 e0 f1 20
Sep 20 18:11:48 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_SA
Sep 20 18:11:48 djpc pluto[9618]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:11:48 djpc pluto[9618]: |    exchange type: ISAKMP_XCHG_IDPROT
Sep 20 18:11:48 djpc pluto[9618]: |    flags: none
Sep 20 18:11:48 djpc pluto[9618]: |    message ID:  00 00 00 00
Sep 20 18:11:48 djpc pluto[9618]: | ***emit ISAKMP Security Association 
Payload:
Sep 20 18:11:48 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_VID
Sep 20 18:11:48 djpc pluto[9618]: |    DOI: ISAKMP_DOI_IPSEC
Sep 20 18:11:48 djpc pluto[9618]: | ****parse IPsec DOI SIT:
Sep 20 18:11:48 djpc pluto[9618]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Sep 20 18:11:48 djpc pluto[9618]: | ****parse ISAKMP Proposal Payload:
Sep 20 18:11:48 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:11:48 djpc pluto[9618]: |    length: 188
Sep 20 18:11:48 djpc pluto[9618]: |    proposal number: 1
Sep 20 18:11:48 djpc pluto[9618]: |    protocol ID: PROTO_ISAKMP
Sep 20 18:11:48 djpc pluto[9618]: |    SPI size: 0
Sep 20 18:11:48 djpc pluto[9618]: |    number of transforms: 5
Sep 20 18:11:48 djpc pluto[9618]: | *****parse ISAKMP Transform Payload 
(ISAKMP):
Sep 20 18:11:48 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_T
Sep 20 18:11:48 djpc pluto[9618]: |    length: 36
Sep 20 18:11:48 djpc pluto[9618]: |    transform number: 1
Sep 20 18:11:48 djpc pluto[9618]: |    transform ID: KEY_IKE
Sep 20 18:11:48 djpc pluto[9618]: | ******parse ISAKMP Oakley attribute:
Sep 20 18:11:48 djpc pluto[9618]: |    af+type: OAKLEY_ENCRYPTION_ALGORITHM
Sep 20 18:11:48 djpc pluto[9618]: |    length/value: 5
Sep 20 18:11:48 djpc pluto[9618]: |    [5 is OAKLEY_3DES_CBC]
Sep 20 18:11:48 djpc pluto[9618]: | ike_alg_enc_ok(ealg=5,key_len=0): 
blocksize=8, keyminlen=192, keydeflen=192, keymaxlen=192, ret=1
Sep 20 18:11:48 djpc pluto[9618]: | ******parse ISAKMP Oakley attribute:
Sep 20 18:11:48 djpc pluto[9618]: |    af+type: OAKLEY_HASH_ALGORITHM
Sep 20 18:11:48 djpc pluto[9618]: |    length/value: 2
Sep 20 18:11:48 djpc pluto[9618]: |    [2 is OAKLEY_SHA1]
Sep 20 18:11:48 djpc pluto[9618]: | ******parse ISAKMP Oakley attribute:
Sep 20 18:11:49 djpc pluto[9618]: |    af+type: OAKLEY_GROUP_DESCRIPTION
Sep 20 18:11:49 djpc pluto[9618]: |    length/value: 14
Sep 20 18:11:49 djpc pluto[9618]: |    [14 is OAKLEY_GROUP_MODP2048]
Sep 20 18:11:49 djpc pluto[9618]: | ******parse ISAKMP Oakley attribute:
Sep 20 18:11:49 djpc pluto[9618]: |    af+type: OAKLEY_AUTHENTICATION_METHOD
Sep 20 18:11:49 djpc pluto[9618]: |    length/value: 1
Sep 20 18:11:49 djpc pluto[9618]: |    [1 is OAKLEY_PRESHARED_KEY]
Sep 20 18:11:49 djpc pluto[9618]: | started looking for secret for 
192.168.1.7->192.168.1.250 of kind PPK_PSK
Sep 20 18:11:49 djpc pluto[9618]: | actually looking for secret for 
192.168.1.7->192.168.1.250 of kind PPK_PSK
Sep 20 18:11:49 djpc pluto[9618]: | 1: compared PSK 192.168.1.250 to 
192.168.1.7 / 192.168.1.250 -> 2
Sep 20 18:11:49 djpc pluto[9618]: | 2: compared PSK 192.168.1.7 to 
192.168.1.7 / 192.168.1.250 -> 6
Sep 20 18:11:49 djpc pluto[9618]: | best_match 0>6 best=0x80fc1c8 (line=11)
Sep 20 18:11:49 djpc pluto[9618]: | concluding with best_match=6 
best=0x80fc1c8 (lineno=11)
Sep 20 18:11:49 djpc pluto[9618]: | ******parse ISAKMP Oakley attribute:
Sep 20 18:11:49 djpc pluto[9618]: |    af+type: OAKLEY_LIFE_TYPE
Sep 20 18:11:49 djpc pluto[9618]: |    length/value: 1
Sep 20 18:11:49 djpc pluto[9618]: |    [1 is OAKLEY_LIFE_SECONDS]
Sep 20 18:11:49 djpc pluto[9618]: | ******parse ISAKMP Oakley attribute:
Sep 20 18:11:49 djpc pluto[9618]: |    af+type: OAKLEY_LIFE_DURATION 
(variable length)
Sep 20 18:11:49 djpc pluto[9618]: |    length/value: 4
Sep 20 18:11:49 djpc pluto[9618]: |    long duration: 28800
Sep 20 18:11:49 djpc pluto[9618]: | Oakley Transform 1 accepted
Sep 20 18:11:49 djpc pluto[9618]: | ****emit IPsec DOI SIT:
Sep 20 18:11:49 djpc pluto[9618]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Sep 20 18:11:49 djpc pluto[9618]: | ****emit ISAKMP Proposal Payload:
Sep 20 18:11:49 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:11:49 djpc pluto[9618]: |    proposal number: 1
Sep 20 18:11:49 djpc pluto[9618]: |    protocol ID: PROTO_ISAKMP
Sep 20 18:11:49 djpc pluto[9618]: |    SPI size: 0
Sep 20 18:11:49 djpc pluto[9618]: |    number of transforms: 1
Sep 20 18:11:49 djpc pluto[9618]: | *****emit ISAKMP Transform Payload 
(ISAKMP):
Sep 20 18:11:49 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:11:49 djpc pluto[9618]: |    transform number: 1
Sep 20 18:11:49 djpc pluto[9618]: |    transform ID: KEY_IKE
Sep 20 18:11:49 djpc pluto[9618]: | emitting 28 raw bytes of attributes 
into ISAKMP Transform Payload (ISAKMP)
Sep 20 18:11:49 djpc pluto[9618]: | attributes  80 01 00 05  80 02 00 02 
  80 04 00 0e  80 03 00 01
Sep 20 18:11:49 djpc pluto[9618]: |   80 0b 00 01  00 0c 00 04  00 00 70 80
Sep 20 18:11:49 djpc pluto[9618]: | emitting length of ISAKMP Transform 
Payload (ISAKMP): 36
Sep 20 18:11:49 djpc pluto[9618]: | emitting length of ISAKMP Proposal 
Payload: 44
Sep 20 18:11:49 djpc pluto[9618]: | emitting length of ISAKMP Security 
Association Payload: 56
Sep 20 18:11:49 djpc pluto[9618]: | ***emit ISAKMP Vendor ID Payload:
Sep 20 18:11:49 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_VID
Sep 20 18:11:49 djpc pluto[9618]: | emitting 12 raw bytes of Vendor ID 
into ISAKMP Vendor ID Payload
Sep 20 18:11:49 djpc pluto[9618]: | Vendor ID  4f 45 7a 7d  46 46 46 66 
  67 72 5f 65
Sep 20 18:11:49 djpc pluto[9618]: | emitting length of ISAKMP Vendor ID 
Payload: 16
Sep 20 18:11:49 djpc pluto[9618]: | ***emit ISAKMP Vendor ID Payload:
Sep 20 18:11:49 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:11:49 djpc pluto[9618]: | emitting 16 raw bytes of DPP Vendor 
ID into ISAKMP Vendor ID Payload
Sep 20 18:11:49 djpc pluto[9618]: | DPP Vendor ID  af ca d7 13  68 a1 f1 
c9  6b 86 96 fc  77 57 01 00
Sep 20 18:11:49 djpc pluto[9618]: | emitting length of ISAKMP Vendor ID 
Payload: 20
Sep 20 18:11:49 djpc pluto[9618]: | sender checking NAT-t: 0 and 0
Sep 20 18:11:49 djpc pluto[9618]: | emitting length of ISAKMP Message: 120
Sep 20 18:11:49 djpc pluto[9618]: | complete state transition with STF_OK
Sep 20 18:11:49 djpc pluto[9618]: "L2TP-PSK" #2: transition from state 
STATE_MAIN_R0 to state STATE_MAIN_R1
Sep 20 18:11:49 djpc pluto[9618]: | sending reply packet to 
192.168.1.250:500 (from port=500)
Sep 20 18:11:49 djpc pluto[9618]: | sending 120 bytes for STATE_MAIN_R0 
through eth0:500 to 192.168.1.250:500:
Sep 20 18:11:49 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46  c0 26 6e 
bf  f9 e0 f1 20
Sep 20 18:11:49 djpc pluto[9618]: |   01 10 02 00  00 00 00 00  00 00 00 
78  0d 00 00 38
Sep 20 18:11:49 djpc pluto[9618]: |   00 00 00 01  00 00 00 01  00 00 00 
2c  01 01 00 01
Sep 20 18:11:49 djpc pluto[9618]: |   00 00 00 24  01 01 00 00  80 01 00 
05  80 02 00 02
Sep 20 18:11:49 djpc pluto[9618]: |   80 04 00 0e  80 03 00 01  80 0b 00 
01  00 0c 00 04
Sep 20 18:11:49 djpc pluto[9618]: |   00 00 70 80  0d 00 00 10  4f 45 7a 
7d  46 46 46 66
Sep 20 18:11:49 djpc pluto[9618]: |   67 72 5f 65  00 00 00 14  af ca d7 
13  68 a1 f1 c9
Sep 20 18:11:49 djpc pluto[9618]: |   6b 86 96 fc  77 57 01 00
Sep 20 18:11:49 djpc pluto[9618]: | inserting event EVENT_RETRANSMIT, 
timeout in 10 seconds for #2
Sep 20 18:11:49 djpc pluto[9618]: "L2TP-PSK" #2: STATE_MAIN_R1: sent 
MR1, expecting MI2
Sep 20 18:11:49 djpc pluto[9618]: | modecfg pull: noquirk policy:push 
not-client
Sep 20 18:11:49 djpc pluto[9618]: | phase 1 is done, looking for phase 1 
to unpend
Sep 20 18:11:49 djpc pluto[9618]: | next event EVENT_RETRANSMIT in 8 
seconds for #1
Sep 20 18:11:49 djpc pluto[9618]: |
Sep 20 18:11:49 djpc pluto[9618]: | *received 312 bytes from 
192.168.1.250:500 on eth0 (port=500)
Sep 20 18:11:49 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46  8d 38 1b 
33  f4 c5 e0 f4
Sep 20 18:11:49 djpc pluto[9618]: |   04 10 02 00  00 00 00 00  00 00 01 
38  0a 00 01 04
Sep 20 18:11:49 djpc pluto[9618]: |   73 bf 0c da  4c 58 98 6a  37 e2 c1 
d2  6d 98 ca f1
Sep 20 18:11:49 djpc pluto[9618]: |   a2 91 c2 29  03 10 c5 b1  19 92 36 
ed  22 33 3c a5
Sep 20 18:11:49 djpc pluto[9618]: |   e1 02 73 54  45 a8 cb 3c  3c ef e6 
7e  02 3d 84 64
Sep 20 18:11:49 djpc pluto[9618]: |   dc 41 1d b8  c8 f4 50 eb  79 f7 ae 
01  12 68 c0 95
Sep 20 18:11:49 djpc pluto[9618]: |   70 f6 89 55  a2 c9 3d 98  7c 0f 13 
16  23 ea 0e b8
Sep 20 18:11:49 djpc pluto[9618]: |   5b 0a ca 33  24 e6 a6 b7  cd 36 f2 
cd  5a f2 2a d8
Sep 20 18:11:49 djpc pluto[9618]: |   ab 6a f8 c3  43 8c 98 78  d9 4a e4 
12  53 cf df bc
Sep 20 18:11:49 djpc pluto[9618]: |   03 51 84 f5  b1 b1 16 3b  45 76 99 
5f  85 0c 0e cb
Sep 20 18:11:49 djpc pluto[9618]: |   85 c9 56 48  07 f5 fb 2c  a1 7a 08 
1b  29 6b 11 8b
Sep 20 18:11:49 djpc pluto[9618]: |   66 34 f3 2b  2d 83 a4 23  17 04 39 
dc  c6 f7 2d e9
Sep 20 18:11:49 djpc pluto[9618]: |   1c f1 21 41  33 91 55 55  83 23 d2 
d2  bd ab 54 0f
Sep 20 18:11:49 djpc pluto[9618]: |   e8 53 1a 10  6c 4c 19 e0  32 d5 77 
f8  12 5d c2 41
Sep 20 18:11:49 djpc pluto[9618]: |   0b fe ee a4  b6 88 61 85  7e 8d 0e 
4b  45 3c ba d3
Sep 20 18:11:49 djpc pluto[9618]: |   11 9c 83 08  4a 80 7c 00  74 eb a9 
93  ea de f2 f9
Sep 20 18:11:49 djpc pluto[9618]: |   b8 d6 67 76  76 19 1f a0  32 10 59 
02  55 88 59 b3
Sep 20 18:11:49 djpc pluto[9618]: |   3d da 95 46  d1 70 10 09  54 55 fe 
1a  44 13 78 d6
Sep 20 18:11:49 djpc pluto[9618]: |   00 00 00 18  4c 66 21 ae  bf 52 46 
ba  2a b3 03 82
Sep 20 18:11:49 djpc pluto[9618]: |   ad 94 9b 9d  07 2c ea 70
Sep 20 18:11:49 djpc pluto[9618]: | **parse ISAKMP Message:
Sep 20 18:11:49 djpc pluto[9618]: |    initiator cookie:
Sep 20 18:11:49 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:49 djpc pluto[9618]: |    responder cookie:
Sep 20 18:11:49 djpc pluto[9618]: |   8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:49 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_KE
Sep 20 18:11:50 djpc pluto[9618]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:11:50 djpc pluto[9618]: |    exchange type: ISAKMP_XCHG_IDPROT
Sep 20 18:11:50 djpc pluto[9618]: |    flags: none
Sep 20 18:11:50 djpc pluto[9618]: |    message ID:  00 00 00 00
Sep 20 18:11:50 djpc pluto[9618]: |    length: 312
Sep 20 18:11:50 djpc pluto[9618]: |  processing packet with exchange 
type=ISAKMP_XCHG_IDPROT (2)
Sep 20 18:11:50 djpc pluto[9618]: | ICOOKIE:  a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:50 djpc pluto[9618]: | RCOOKIE:  8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:50 djpc pluto[9618]: | peer:  c0 a8 01 fa
Sep 20 18:11:50 djpc pluto[9618]: | state hash entry 0
Sep 20 18:11:50 djpc pluto[9618]: | peer and cookies match on #1, 
provided msgid 00000000 vs 00000000
Sep 20 18:11:50 djpc pluto[9618]: | state object #1 found, in STATE_MAIN_R1
Sep 20 18:11:50 djpc pluto[9618]: | processing connection L2TP-PSK
Sep 20 18:11:50 djpc pluto[9618]: | ***parse ISAKMP Key Exchange Payload:
Sep 20 18:11:50 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONCE
Sep 20 18:11:50 djpc pluto[9618]: |    length: 260
Sep 20 18:11:50 djpc pluto[9618]: | ***parse ISAKMP Nonce Payload:
Sep 20 18:11:50 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:11:50 djpc pluto[9618]: |    length: 24
Sep 20 18:11:50 djpc pluto[9618]: | **emit ISAKMP Message:
Sep 20 18:11:50 djpc pluto[9618]: |    initiator cookie:
Sep 20 18:11:50 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:50 djpc pluto[9618]: |    responder cookie:
Sep 20 18:11:50 djpc pluto[9618]: |   8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:50 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_KE
Sep 20 18:11:50 djpc pluto[9618]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:11:50 djpc pluto[9618]: |    exchange type: ISAKMP_XCHG_IDPROT
Sep 20 18:11:50 djpc pluto[9618]: |    flags: none
Sep 20 18:11:50 djpc pluto[9618]: |    message ID:  00 00 00 00
Sep 20 18:11:50 djpc pluto[9618]: | DH public value received:
Sep 20 18:11:50 djpc pluto[9618]: |   73 bf 0c da  4c 58 98 6a  37 e2 c1 
d2  6d 98 ca f1
Sep 20 18:11:50 djpc pluto[9618]: |   a2 91 c2 29  03 10 c5 b1  19 92 36 
ed  22 33 3c a5
Sep 20 18:11:50 djpc pluto[9618]: |   e1 02 73 54  45 a8 cb 3c  3c ef e6 
7e  02 3d 84 64
Sep 20 18:11:50 djpc pluto[9618]: |   dc 41 1d b8  c8 f4 50 eb  79 f7 ae 
01  12 68 c0 95
Sep 20 18:11:50 djpc pluto[9618]: |   70 f6 89 55  a2 c9 3d 98  7c 0f 13 
16  23 ea 0e b8
Sep 20 18:11:50 djpc pluto[9618]: |   5b 0a ca 33  24 e6 a6 b7  cd 36 f2 
cd  5a f2 2a d8
Sep 20 18:11:50 djpc pluto[9618]: |   ab 6a f8 c3  43 8c 98 78  d9 4a e4 
12  53 cf df bc
Sep 20 18:11:50 djpc pluto[9618]: |   03 51 84 f5  b1 b1 16 3b  45 76 99 
5f  85 0c 0e cb
Sep 20 18:11:50 djpc pluto[9618]: |   85 c9 56 48  07 f5 fb 2c  a1 7a 08 
1b  29 6b 11 8b
Sep 20 18:11:50 djpc pluto[9618]: |   66 34 f3 2b  2d 83 a4 23  17 04 39 
dc  c6 f7 2d e9
Sep 20 18:11:50 djpc pluto[9618]: |   1c f1 21 41  33 91 55 55  83 23 d2 
d2  bd ab 54 0f
Sep 20 18:11:50 djpc pluto[9618]: |   e8 53 1a 10  6c 4c 19 e0  32 d5 77 
f8  12 5d c2 41
Sep 20 18:11:50 djpc pluto[9618]: |   0b fe ee a4  b6 88 61 85  7e 8d 0e 
4b  45 3c ba d3
Sep 20 18:11:50 djpc pluto[9618]: |   11 9c 83 08  4a 80 7c 00  74 eb a9 
93  ea de f2 f9
Sep 20 18:11:50 djpc pluto[9618]: |   b8 d6 67 76  76 19 1f a0  32 10 59 
02  55 88 59 b3
Sep 20 18:11:50 djpc pluto[9618]: |   3d da 95 46  d1 70 10 09  54 55 fe 
1a  44 13 78 d6
Sep 20 18:11:50 djpc pluto[9618]: | inI2: checking NAT-t: 0 and 0
Sep 20 18:11:50 djpc pluto[9618]: | 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
Sep 20 18:11:50 djpc pluto[9618]: | asking helper 0 to do build_kenonce 
op on seq: 1
Sep 20 18:11:50 djpc pluto[9618]: | inserting event EVENT_CRYPTO_FAILED, 
timeout in 300 seconds for #1
Sep 20 18:11:50 djpc pluto[9649]: ! helper -1 doing build_kenonce op id: 1
Sep 20 18:11:50 djpc pluto[9618]: | complete state transition with 
STF_SUSPEND
Sep 20 18:11:50 djpc pluto[9649]: ! Local DH secret:
Sep 20 18:11:50 djpc pluto[9618]: | next event EVENT_RETRANSMIT in 9 
seconds for #2
Sep 20 18:11:50 djpc pluto[9649]: !   0e 1b 8e 14  aa 79 1a 6d  c6 5a f1 
e6  af 88 37 dc
Sep 20 18:11:50 djpc pluto[9618]: |
Sep 20 18:11:50 djpc pluto[9649]: !   e5 11 cd b5  a1 df 32 08  2e e8 be 
92  97 d6 63 fa
Sep 20 18:11:50 djpc pluto[9618]: | *received 312 bytes from 
192.168.1.250:500 on eth0 (port=500)
Sep 20 18:11:50 djpc pluto[9649]: ! Public DH value sent:
Sep 20 18:11:50 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46  8d 38 1b 
33  f4 c5 e0 f4
Sep 20 18:11:50 djpc pluto[9649]: !   6d 84 f9 9d  76 1b 28 a0  cf 4a 67 
5a  5a b8 73 5d
Sep 20 18:11:50 djpc pluto[9618]: |   04 10 02 00  00 00 00 00  00 00 01 
38  0a 00 01 04
Sep 20 18:11:50 djpc pluto[9649]: !   c4 13 78 4e  2f b9 72 5d  5f b4 83 
59  8f 0f 2f 4f
Sep 20 18:11:50 djpc pluto[9618]: |   73 bf 0c da  4c 58 98 6a  37 e2 c1 
d2  6d 98 ca f1
Sep 20 18:11:50 djpc pluto[9649]: !   c5 48 a1 63  9e 54 4a 04  90 31 a7 
e0  a0 31 5b a8
Sep 20 18:11:50 djpc pluto[9618]: |   a2 91 c2 29  03 10 c5 b1  19 92 36 
ed  22 33 3c a5
Sep 20 18:11:50 djpc pluto[9649]: !   02 4e 98 0a  93 36 74 92  f7 cd dd 
5c  7b 63 0a 7c
Sep 20 18:11:50 djpc pluto[9618]: |   e1 02 73 54  45 a8 cb 3c  3c ef e6 
7e  02 3d 84 64
Sep 20 18:11:50 djpc pluto[9649]: !   fe eb 91 cc  24 81 e4 ea  22 c7 af 
07  9b 4f 01 fb
Sep 20 18:11:50 djpc pluto[9618]: |   dc 41 1d b8  c8 f4 50 eb  79 f7 ae 
01  12 68 c0 95
Sep 20 18:11:50 djpc pluto[9649]: !   05 e5 ee ae  37 7b 42 6a  02 19 fc 
cb  7f 35 14 38
Sep 20 18:11:50 djpc pluto[9618]: |   70 f6 89 55  a2 c9 3d 98  7c 0f 13 
16  23 ea 0e b8
Sep 20 18:11:50 djpc pluto[9649]: !   54 e5 c4 c1  42 26 ed e5  e0 36 3c 
f7  55 19 d5 de
Sep 20 18:11:50 djpc pluto[9618]: |   5b 0a ca 33  24 e6 a6 b7  cd 36 f2 
cd  5a f2 2a d8
Sep 20 18:11:50 djpc pluto[9649]: !   76 ee 86 81  0b 93 53 3d  d0 35 37 
0c  0c 14 28 53
Sep 20 18:11:50 djpc pluto[9618]: |   ab 6a f8 c3  43 8c 98 78  d9 4a e4 
12  53 cf df bc
Sep 20 18:11:50 djpc pluto[9649]: !   1e e1 40 5e  33 72 9d b2  69 52 be 
05  c2 59 3c 25
Sep 20 18:11:50 djpc pluto[9618]: |   03 51 84 f5  b1 b1 16 3b  45 76 99 
5f  85 0c 0e cb
Sep 20 18:11:50 djpc pluto[9649]: !   fc 51 f7 49  03 46 b9 c2  93 96 83 
52  bc ad 66 5b
Sep 20 18:11:50 djpc pluto[9618]: |   85 c9 56 48  07 f5 fb 2c  a1 7a 08 
1b  29 6b 11 8b
Sep 20 18:11:50 djpc pluto[9649]: !   da e5 09 eb  f9 47 b7 68  1e d3 fd 
d9  c5 19 46 39
Sep 20 18:11:50 djpc pluto[9618]: |   66 34 f3 2b  2d 83 a4 23  17 04 39 
dc  c6 f7 2d e9
Sep 20 18:11:50 djpc pluto[9649]: !   66 85 a8 54  2a 26 d8 88  a1 0a 81 
b2  35 5b ba 60
Sep 20 18:11:50 djpc pluto[9618]: |   1c f1 21 41  33 91 55 55  83 23 d2 
d2  bd ab 54 0f
Sep 20 18:11:50 djpc pluto[9649]: !   7d ee ad c6  11 9b bc 58  35 1c 3c 
63  a4 3d ec ed
Sep 20 18:11:50 djpc pluto[9618]: |   e8 53 1a 10  6c 4c 19 e0  32 d5 77 
f8  12 5d c2 41
Sep 20 18:11:50 djpc pluto[9649]: !   fd 57 91 9d  1e ef 79 ad  ae 3e 18 
69  5e 98 32 2b
Sep 20 18:11:50 djpc pluto[9618]: |   0b fe ee a4  b6 88 61 85  7e 8d 0e 
4b  45 3c ba d3
Sep 20 18:11:50 djpc pluto[9649]: !   71 9d e2 f5  a8 9b 68 1a  15 ea b3 
be  2f 30 d0 08
Sep 20 18:11:50 djpc pluto[9618]: |   11 9c 83 08  4a 80 7c 00  74 eb a9 
93  ea de f2 f9
Sep 20 18:11:50 djpc pluto[9649]: !   b8 d9 8c 02  c0 5f bd 62  58 a0 26 
89  48 33 c7 3b
Sep 20 18:11:50 djpc pluto[9618]: |   b8 d6 67 76  76 19 1f a0  32 10 59 
02  55 88 59 b3
Sep 20 18:11:50 djpc pluto[9649]: ! Generated nonce:
Sep 20 18:11:50 djpc pluto[9618]: |   3d da 95 46  d1 70 10 09  54 55 fe 
1a  44 13 78 d6
Sep 20 18:11:50 djpc pluto[9649]: !   bb 4f c9 48  6a 44 2c d0  a8 a2 f6 
9a  ad 5c 61 71
Sep 20 18:11:50 djpc pluto[9618]: |   00 00 00 18  4c 66 21 ae  bf 52 46 
ba  2a b3 03 82
Sep 20 18:11:50 djpc pluto[9618]: |   ad 94 9b 9d  07 2c ea 70
Sep 20 18:11:50 djpc pluto[9618]: | **parse ISAKMP Message:
Sep 20 18:11:50 djpc pluto[9618]: |    initiator cookie:
Sep 20 18:11:50 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:51 djpc pluto[9618]: |    responder cookie:
Sep 20 18:11:51 djpc pluto[9618]: |   8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:51 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_KE
Sep 20 18:11:51 djpc pluto[9618]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:11:51 djpc pluto[9618]: |    exchange type: ISAKMP_XCHG_IDPROT
Sep 20 18:11:51 djpc pluto[9618]: |    flags: none
Sep 20 18:11:51 djpc pluto[9618]: |    message ID:  00 00 00 00
Sep 20 18:11:51 djpc pluto[9618]: |    length: 312
Sep 20 18:11:51 djpc pluto[9618]: |  processing packet with exchange 
type=ISAKMP_XCHG_IDPROT (2)
Sep 20 18:11:51 djpc pluto[9618]: | ICOOKIE:  a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:51 djpc pluto[9618]: | RCOOKIE:  8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:51 djpc pluto[9618]: | peer:  c0 a8 01 fa
Sep 20 18:11:51 djpc pluto[9618]: | state hash entry 0
Sep 20 18:11:51 djpc pluto[9618]: | peer and cookies match on #1, 
provided msgid 00000000 vs 00000000
Sep 20 18:11:51 djpc pluto[9618]: | state object #1 found, in STATE_MAIN_R1
Sep 20 18:11:51 djpc pluto[9618]: | processing connection L2TP-PSK
Sep 20 18:11:51 djpc pluto[9618]: "L2TP-PSK" #1: discarding packet 
received during asynchronous work (DNS or crypto) in STATE_MAIN_R1
Sep 20 18:11:51 djpc pluto[9618]: | next event EVENT_RETRANSMIT in 8 
seconds for #2
Sep 20 18:11:51 djpc pluto[9618]: |
Sep 20 18:11:51 djpc pluto[9618]: | *received 312 bytes from 
192.168.1.250:500 on eth0 (port=500)
Sep 20 18:11:51 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46  8d 38 1b 
33  f4 c5 e0 f4
Sep 20 18:11:51 djpc pluto[9618]: |   04 10 02 00  00 00 00 00  00 00 01 
38  0a 00 01 04
Sep 20 18:11:51 djpc pluto[9618]: |   73 bf 0c da  4c 58 98 6a  37 e2 c1 
d2  6d 98 ca f1
Sep 20 18:11:51 djpc pluto[9618]: |   a2 91 c2 29  03 10 c5 b1  19 92 36 
ed  22 33 3c a5
Sep 20 18:11:51 djpc pluto[9618]: |   e1 02 73 54  45 a8 cb 3c  3c ef e6 
7e  02 3d 84 64
Sep 20 18:11:51 djpc pluto[9618]: |   dc 41 1d b8  c8 f4 50 eb  79 f7 ae 
01  12 68 c0 95
Sep 20 18:11:51 djpc pluto[9618]: |   70 f6 89 55  a2 c9 3d 98  7c 0f 13 
16  23 ea 0e b8
Sep 20 18:11:51 djpc pluto[9618]: |   5b 0a ca 33  24 e6 a6 b7  cd 36 f2 
cd  5a f2 2a d8
Sep 20 18:11:51 djpc pluto[9618]: |   ab 6a f8 c3  43 8c 98 78  d9 4a e4 
12  53 cf df bc
Sep 20 18:11:51 djpc pluto[9618]: |   03 51 84 f5  b1 b1 16 3b  45 76 99 
5f  85 0c 0e cb
Sep 20 18:11:51 djpc pluto[9618]: |   85 c9 56 48  07 f5 fb 2c  a1 7a 08 
1b  29 6b 11 8b
Sep 20 18:11:51 djpc pluto[9618]: |   66 34 f3 2b  2d 83 a4 23  17 04 39 
dc  c6 f7 2d e9
Sep 20 18:11:51 djpc pluto[9618]: |   1c f1 21 41  33 91 55 55  83 23 d2 
d2  bd ab 54 0f
Sep 20 18:11:51 djpc pluto[9618]: |   e8 53 1a 10  6c 4c 19 e0  32 d5 77 
f8  12 5d c2 41
Sep 20 18:11:51 djpc pluto[9618]: |   0b fe ee a4  b6 88 61 85  7e 8d 0e 
4b  45 3c ba d3
Sep 20 18:11:51 djpc pluto[9618]: |   11 9c 83 08  4a 80 7c 00  74 eb a9 
93  ea de f2 f9
Sep 20 18:11:51 djpc pluto[9618]: |   b8 d6 67 76  76 19 1f a0  32 10 59 
02  55 88 59 b3
Sep 20 18:11:51 djpc pluto[9618]: |   3d da 95 46  d1 70 10 09  54 55 fe 
1a  44 13 78 d6
Sep 20 18:11:51 djpc pluto[9618]: |   00 00 00 18  4c 66 21 ae  bf 52 46 
ba  2a b3 03 82
Sep 20 18:11:51 djpc pluto[9618]: |   ad 94 9b 9d  07 2c ea 70
Sep 20 18:11:51 djpc pluto[9618]: | **parse ISAKMP Message:
Sep 20 18:11:51 djpc pluto[9618]: |    initiator cookie:
Sep 20 18:11:51 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:51 djpc pluto[9618]: |    responder cookie:
Sep 20 18:11:51 djpc pluto[9618]: |   8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:51 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_KE
Sep 20 18:11:51 djpc pluto[9618]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:11:51 djpc pluto[9618]: |    exchange type: ISAKMP_XCHG_IDPROT
Sep 20 18:11:51 djpc pluto[9618]: |    flags: none
Sep 20 18:11:51 djpc pluto[9618]: |    message ID:  00 00 00 00
Sep 20 18:11:51 djpc pluto[9618]: |    length: 312
Sep 20 18:11:51 djpc pluto[9618]: |  processing packet with exchange 
type=ISAKMP_XCHG_IDPROT (2)
Sep 20 18:11:51 djpc pluto[9618]: | ICOOKIE:  a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:51 djpc pluto[9618]: | RCOOKIE:  8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:51 djpc pluto[9618]: | peer:  c0 a8 01 fa
Sep 20 18:11:51 djpc pluto[9618]: | state hash entry 0
Sep 20 18:11:51 djpc pluto[9618]: | peer and cookies match on #1, 
provided msgid 00000000 vs 00000000
Sep 20 18:11:51 djpc pluto[9618]: | state object #1 found, in STATE_MAIN_R1
Sep 20 18:11:51 djpc pluto[9618]: | processing connection L2TP-PSK
Sep 20 18:11:51 djpc pluto[9618]: "L2TP-PSK" #1: discarding packet 
received during asynchronous work (DNS or crypto) in STATE_MAIN_R1
Sep 20 18:11:51 djpc pluto[9618]: | helper 0 has work (cnt now 0)
Sep 20 18:11:51 djpc pluto[9618]: | helper 0 replies to sequence 1
Sep 20 18:11:51 djpc pluto[9618]: | calling callback function 0x8065e14
Sep 20 18:11:51 djpc pluto[9618]: | main inI2_outR2: calculated 
ke+nonce, sending R2
Sep 20 18:11:51 djpc pluto[9618]: | processing connection L2TP-PSK
Sep 20 18:11:51 djpc pluto[9618]: | ***emit ISAKMP Key Exchange Payload:
Sep 20 18:11:51 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONCE
Sep 20 18:11:51 djpc pluto[9618]: | emitting 256 raw bytes of keyex 
value into ISAKMP Key Exchange Payload
Sep 20 18:11:51 djpc pluto[9618]: | keyex value  6d 84 f9 9d  76 1b 28 
a0  cf 4a 67 5a  5a b8 73 5d
Sep 20 18:11:51 djpc pluto[9618]: |   c4 13 78 4e  2f b9 72 5d  5f b4 83 
59  8f 0f 2f 4f
Sep 20 18:11:51 djpc pluto[9618]: |   c5 48 a1 63  9e 54 4a 04  90 31 a7 
e0  a0 31 5b a8
Sep 20 18:11:51 djpc pluto[9618]: |   02 4e 98 0a  93 36 74 92  f7 cd dd 
5c  7b 63 0a 7c
Sep 20 18:11:51 djpc pluto[9618]: |   fe eb 91 cc  24 81 e4 ea  22 c7 af 
07  9b 4f 01 fb
Sep 20 18:11:51 djpc pluto[9618]: |   05 e5 ee ae  37 7b 42 6a  02 19 fc 
cb  7f 35 14 38
Sep 20 18:11:51 djpc pluto[9618]: |   54 e5 c4 c1  42 26 ed e5  e0 36 3c 
f7  55 19 d5 de
Sep 20 18:11:51 djpc pluto[9618]: |   76 ee 86 81  0b 93 53 3d  d0 35 37 
0c  0c 14 28 53
Sep 20 18:11:51 djpc pluto[9618]: |   1e e1 40 5e  33 72 9d b2  69 52 be 
05  c2 59 3c 25
Sep 20 18:11:51 djpc pluto[9618]: |   fc 51 f7 49  03 46 b9 c2  93 96 83 
52  bc ad 66 5b
Sep 20 18:11:51 djpc pluto[9618]: |   da e5 09 eb  f9 47 b7 68  1e d3 fd 
d9  c5 19 46 39
Sep 20 18:11:51 djpc pluto[9618]: |   66 85 a8 54  2a 26 d8 88  a1 0a 81 
b2  35 5b ba 60
Sep 20 18:11:51 djpc pluto[9618]: |   7d ee ad c6  11 9b bc 58  35 1c 3c 
63  a4 3d ec ed
Sep 20 18:11:51 djpc pluto[9618]: |   fd 57 91 9d  1e ef 79 ad  ae 3e 18 
69  5e 98 32 2b
Sep 20 18:11:51 djpc pluto[9618]: |   71 9d e2 f5  a8 9b 68 1a  15 ea b3 
be  2f 30 d0 08
Sep 20 18:11:51 djpc pluto[9618]: |   b8 d9 8c 02  c0 5f bd 62  58 a0 26 
89  48 33 c7 3b
Sep 20 18:11:51 djpc pluto[9618]: | emitting length of ISAKMP Key 
Exchange Payload: 260
Sep 20 18:11:51 djpc pluto[9618]: | ***emit ISAKMP Nonce Payload:
Sep 20 18:11:51 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:11:51 djpc pluto[9618]: | emitting 16 raw bytes of Nr into 
ISAKMP Nonce Payload
Sep 20 18:11:51 djpc pluto[9618]: | Nr  bb 4f c9 48  6a 44 2c d0  a8 a2 
f6 9a  ad 5c 61 71
Sep 20 18:11:51 djpc pluto[9618]: | emitting length of ISAKMP Nonce 
Payload: 20
Sep 20 18:11:51 djpc pluto[9618]: | emitting length of ISAKMP Message: 308
Sep 20 18:11:51 djpc pluto[9618]: | started looking for secret for 
192.168.1.7->192.168.1.250 of kind PPK_PSK
Sep 20 18:11:51 djpc pluto[9618]: | actually looking for secret for 
192.168.1.7->192.168.1.250 of kind PPK_PSK
Sep 20 18:11:51 djpc pluto[9618]: | 1: compared PSK 192.168.1.250 to 
192.168.1.7 / 192.168.1.250 -> 2
Sep 20 18:11:51 djpc pluto[9618]: | 2: compared PSK 192.168.1.7 to 
192.168.1.7 / 192.168.1.250 -> 6
Sep 20 18:11:51 djpc pluto[9618]: | best_match 0>6 best=0x80fc1c8 (line=11)
Sep 20 18:11:52 djpc pluto[9618]: | concluding with best_match=6 
best=0x80fc1c8 (lineno=11)
Sep 20 18:11:52 djpc pluto[9618]: | calc_dh_shared(): time elapsed 
(OAKLEY_GROUP_MODP2048): 10879 usec
Sep 20 18:11:52 djpc pluto[9618]: | DH shared secret:
Sep 20 18:11:52 djpc pluto[9618]: |   b4 2f 52 cb  45 0e 5e b7  47 09 6f 
ef  3f f3 cc 1a
Sep 20 18:11:52 djpc pluto[9618]: |   ba a7 a2 0e  e4 f6 f2 f4  03 33 72 
95  a5 53 fc 6c
Sep 20 18:11:52 djpc pluto[9618]: |   aa e9 8d 9b  cc f5 ad ad  22 25 41 
6e  29 26 4a 88
Sep 20 18:11:52 djpc pluto[9618]: |   bd 95 86 a4  da 05 38 84  a4 f0 ef 
f5  c4 bb 48 bb
Sep 20 18:11:52 djpc pluto[9618]: |   71 e1 ad f0  a2 88 65 31  9e 14 3b 
34  00 d4 45 f1
Sep 20 18:11:52 djpc pluto[9618]: |   a9 c2 5f 41  3b 9c 89 ec  33 c0 93 
f8  c1 7d 64 55
Sep 20 18:11:52 djpc pluto[9618]: |   08 ef ea 1d  9d 45 60 2b  2f b2 34 
f8  08 04 e1 7f
Sep 20 18:11:52 djpc pluto[9618]: |   87 5a 29 cd  d6 37 4e 0c  6c 5b f5 
2a  04 4c d2 80
Sep 20 18:11:52 djpc pluto[9618]: |   1b a1 12 a9  94 9e c2 1c  6c 40 4f 
cd  c0 56 c7 0e
Sep 20 18:11:52 djpc pluto[9618]: |   ef a6 e9 10  20 7d 91 39  97 02 51 
4b  58 00 42 71
Sep 20 18:11:52 djpc pluto[9618]: |   17 07 6a bd  8a 6e 9c ee  d6 50 d7 
e8  d2 0d 1b 9d
Sep 20 18:11:52 djpc pluto[9618]: |   29 dc f3 79  f4 b9 42 e5  f1 db 5d 
09  b0 5e 18 da
Sep 20 18:11:52 djpc pluto[9618]: |   90 44 8a 2d  e3 f2 77 bd  bf 18 5c 
df  7f 30 19 82
Sep 20 18:11:52 djpc pluto[9618]: |   7e a7 08 7a  81 14 9c 3f  d4 7c ac 
4d  ac 58 39 1f
Sep 20 18:11:52 djpc pluto[9618]: |   1c 95 49 7c  7f 12 d2 35  52 c1 3e 
60  82 7f a3 a0
Sep 20 18:11:52 djpc pluto[9618]: |   24 32 cb d2  d5 b8 68 f3  41 ea fc 
88  99 f5 2c a8
Sep 20 18:11:52 djpc pluto[9618]: | Skey inputs (PSK+NI+NR)
Sep 20 18:11:52 djpc pluto[9618]: | ni:   4c 66 21 ae  bf 52 46 ba  2a 
b3 03 82  ad 94 9b 9d
Sep 20 18:11:52 djpc pluto[9618]: |   07 2c ea 70
Sep 20 18:11:52 djpc pluto[9618]: | nr:   bb 4f c9 48  6a 44 2c d0  a8 
a2 f6 9a  ad 5c 61 71
Sep 20 18:11:52 djpc pluto[9618]: | keyid:   74 1d 2e db  f7 06 be fb 
38 b7 b9 75  6b 2a 84 f6
Sep 20 18:11:52 djpc pluto[9618]: |   59 9c 23 92
Sep 20 18:11:52 djpc pluto[9618]: | DH_i:  73 bf 0c da  4c 58 98 6a  37 
e2 c1 d2  6d 98 ca f1
Sep 20 18:11:52 djpc pluto[9618]: |   a2 91 c2 29  03 10 c5 b1  19 92 36 
ed  22 33 3c a5
Sep 20 18:11:52 djpc pluto[9618]: |   e1 02 73 54  45 a8 cb 3c  3c ef e6 
7e  02 3d 84 64
Sep 20 18:11:52 djpc pluto[9618]: |   dc 41 1d b8  c8 f4 50 eb  79 f7 ae 
01  12 68 c0 95
Sep 20 18:11:52 djpc pluto[9618]: |   70 f6 89 55  a2 c9 3d 98  7c 0f 13 
16  23 ea 0e b8
Sep 20 18:11:52 djpc pluto[9618]: |   5b 0a ca 33  24 e6 a6 b7  cd 36 f2 
cd  5a f2 2a d8
Sep 20 18:11:52 djpc pluto[9618]: |   ab 6a f8 c3  43 8c 98 78  d9 4a e4 
12  53 cf df bc
Sep 20 18:11:52 djpc pluto[9618]: |   03 51 84 f5  b1 b1 16 3b  45 76 99 
5f  85 0c 0e cb
Sep 20 18:11:52 djpc pluto[9618]: |   85 c9 56 48  07 f5 fb 2c  a1 7a 08 
1b  29 6b 11 8b
Sep 20 18:11:52 djpc pluto[9618]: |   66 34 f3 2b  2d 83 a4 23  17 04 39 
dc  c6 f7 2d e9
Sep 20 18:11:52 djpc pluto[9618]: |   1c f1 21 41  33 91 55 55  83 23 d2 
d2  bd ab 54 0f
Sep 20 18:11:52 djpc pluto[9618]: |   e8 53 1a 10  6c 4c 19 e0  32 d5 77 
f8  12 5d c2 41
Sep 20 18:11:52 djpc pluto[9618]: |   0b fe ee a4  b6 88 61 85  7e 8d 0e 
4b  45 3c ba d3
Sep 20 18:11:52 djpc pluto[9618]: |   11 9c 83 08  4a 80 7c 00  74 eb a9 
93  ea de f2 f9
Sep 20 18:11:52 djpc pluto[9618]: |   b8 d6 67 76  76 19 1f a0  32 10 59 
02  55 88 59 b3
Sep 20 18:11:52 djpc pluto[9618]: |   3d da 95 46  d1 70 10 09  54 55 fe 
1a  44 13 78 d6
Sep 20 18:11:52 djpc pluto[9618]: | DH_r:  6d 84 f9 9d  76 1b 28 a0  cf 
4a 67 5a  5a b8 73 5d
Sep 20 18:11:52 djpc pluto[9618]: |   c4 13 78 4e  2f b9 72 5d  5f b4 83 
59  8f 0f 2f 4f
Sep 20 18:11:52 djpc pluto[9618]: |   c5 48 a1 63  9e 54 4a 04  90 31 a7 
e0  a0 31 5b a8
Sep 20 18:11:52 djpc pluto[9618]: |   02 4e 98 0a  93 36 74 92  f7 cd dd 
5c  7b 63 0a 7c
Sep 20 18:11:52 djpc pluto[9618]: |   fe eb 91 cc  24 81 e4 ea  22 c7 af 
07  9b 4f 01 fb
Sep 20 18:11:52 djpc pluto[9618]: |   05 e5 ee ae  37 7b 42 6a  02 19 fc 
cb  7f 35 14 38
Sep 20 18:11:52 djpc pluto[9618]: |   54 e5 c4 c1  42 26 ed e5  e0 36 3c 
f7  55 19 d5 de
Sep 20 18:11:52 djpc pluto[9618]: |   76 ee 86 81  0b 93 53 3d  d0 35 37 
0c  0c 14 28 53
Sep 20 18:11:52 djpc pluto[9618]: |   1e e1 40 5e  33 72 9d b2  69 52 be 
05  c2 59 3c 25
Sep 20 18:11:52 djpc pluto[9618]: |   fc 51 f7 49  03 46 b9 c2  93 96 83 
52  bc ad 66 5b
Sep 20 18:11:52 djpc pluto[9618]: |   da e5 09 eb  f9 47 b7 68  1e d3 fd 
d9  c5 19 46 39
Sep 20 18:11:52 djpc pluto[9618]: |   66 85 a8 54  2a 26 d8 88  a1 0a 81 
b2  35 5b ba 60
Sep 20 18:11:52 djpc pluto[9618]: |   7d ee ad c6  11 9b bc 58  35 1c 3c 
63  a4 3d ec ed
Sep 20 18:11:52 djpc pluto[9618]: |   fd 57 91 9d  1e ef 79 ad  ae 3e 18 
69  5e 98 32 2b
Sep 20 18:11:52 djpc pluto[9618]: |   71 9d e2 f5  a8 9b 68 1a  15 ea b3 
be  2f 30 d0 08
Sep 20 18:11:52 djpc pluto[9618]: |   b8 d9 8c 02  c0 5f bd 62  58 a0 26 
89  48 33 c7 3b
Sep 20 18:11:52 djpc pluto[9618]: | Skeyid:    74 1d 2e db  f7 06 be fb 
  38 b7 b9 75  6b 2a 84 f6
Sep 20 18:11:52 djpc pluto[9618]: |   59 9c 23 92
Sep 20 18:11:52 djpc pluto[9618]: | Skeyid_d:  95 72 3a 8b  1c b4 ac 6d 
  f3 b8 2d 07  3d 5a a1 b5
Sep 20 18:11:52 djpc pluto[9618]: |   d4 b9 b2 ca
Sep 20 18:11:52 djpc pluto[9618]: | Skeyid_a:  0c e2 81 f2  2b 83 b5 9f 
  1e f9 3e 29  1e 65 b6 20
Sep 20 18:11:52 djpc pluto[9618]: |   de 64 25 48
Sep 20 18:11:52 djpc pluto[9618]: | Skeyid_e:  fb 2a e0 48  34 b9 e6 04 
  9c 6d 06 b8  a0 cb 57 da
Sep 20 18:11:52 djpc pluto[9618]: |   e5 4e 3c f2
Sep 20 18:11:52 djpc pluto[9618]: | enc key:  de b6 9a d7  5f 8a cb fe 
37 a1 25 c8  88 9d d5 50
Sep 20 18:11:52 djpc pluto[9618]: |   47 08 47 50  24 ee 25 4e
Sep 20 18:11:52 djpc pluto[9618]: | IV:  c9 3e fa 95  79 1a 6b b0  5a 97 
26 17  81 5d c9 6f
Sep 20 18:11:52 djpc pluto[9618]: |   2b 3b 06 6d
Sep 20 18:11:52 djpc pluto[9618]: | complete state transition with STF_OK
Sep 20 18:11:52 djpc pluto[9618]: "L2TP-PSK" #1: transition from state 
STATE_MAIN_R1 to state STATE_MAIN_R2
Sep 20 18:11:52 djpc pluto[9618]: | sending reply packet to 
192.168.1.250:500 (from port=500)
Sep 20 18:11:52 djpc pluto[9618]: | sending 308 bytes for STATE_MAIN_R1 
through eth0:500 to 192.168.1.250:500:
Sep 20 18:11:52 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46  8d 38 1b 
33  f4 c5 e0 f4
Sep 20 18:11:52 djpc pluto[9618]: |   04 10 02 00  00 00 00 00  00 00 01 
34  0a 00 01 04
Sep 20 18:11:52 djpc pluto[9618]: |   6d 84 f9 9d  76 1b 28 a0  cf 4a 67 
5a  5a b8 73 5d
Sep 20 18:11:52 djpc pluto[9618]: |   c4 13 78 4e  2f b9 72 5d  5f b4 83 
59  8f 0f 2f 4f
Sep 20 18:11:52 djpc pluto[9618]: |   c5 48 a1 63  9e 54 4a 04  90 31 a7 
e0  a0 31 5b a8
Sep 20 18:11:52 djpc pluto[9618]: |   02 4e 98 0a  93 36 74 92  f7 cd dd 
5c  7b 63 0a 7c
Sep 20 18:11:52 djpc pluto[9618]: |   fe eb 91 cc  24 81 e4 ea  22 c7 af 
07  9b 4f 01 fb
Sep 20 18:11:52 djpc pluto[9618]: |   05 e5 ee ae  37 7b 42 6a  02 19 fc 
cb  7f 35 14 38
Sep 20 18:11:52 djpc pluto[9618]: |   54 e5 c4 c1  42 26 ed e5  e0 36 3c 
f7  55 19 d5 de
Sep 20 18:11:52 djpc pluto[9618]: |   76 ee 86 81  0b 93 53 3d  d0 35 37 
0c  0c 14 28 53
Sep 20 18:11:52 djpc pluto[9618]: |   1e e1 40 5e  33 72 9d b2  69 52 be 
05  c2 59 3c 25
Sep 20 18:11:52 djpc pluto[9618]: |   fc 51 f7 49  03 46 b9 c2  93 96 83 
52  bc ad 66 5b
Sep 20 18:11:52 djpc pluto[9618]: |   da e5 09 eb  f9 47 b7 68  1e d3 fd 
d9  c5 19 46 39
Sep 20 18:11:52 djpc pluto[9618]: |   66 85 a8 54  2a 26 d8 88  a1 0a 81 
b2  35 5b ba 60
Sep 20 18:11:52 djpc pluto[9618]: |   7d ee ad c6  11 9b bc 58  35 1c 3c 
63  a4 3d ec ed
Sep 20 18:11:52 djpc pluto[9618]: |   fd 57 91 9d  1e ef 79 ad  ae 3e 18 
69  5e 98 32 2b
Sep 20 18:11:52 djpc pluto[9618]: |   71 9d e2 f5  a8 9b 68 1a  15 ea b3 
be  2f 30 d0 08
Sep 20 18:11:52 djpc pluto[9618]: |   b8 d9 8c 02  c0 5f bd 62  58 a0 26 
89  48 33 c7 3b
Sep 20 18:11:52 djpc pluto[9618]: |   00 00 00 14  bb 4f c9 48  6a 44 2c 
d0  a8 a2 f6 9a
Sep 20 18:11:52 djpc pluto[9618]: |   ad 5c 61 71
Sep 20 18:11:52 djpc pluto[9618]: | inserting event EVENT_RETRANSMIT, 
timeout in 10 seconds for #1
Sep 20 18:11:52 djpc pluto[9618]: "L2TP-PSK" #1: STATE_MAIN_R2: sent 
MR2, expecting MI3
Sep 20 18:11:52 djpc pluto[9618]: | modecfg pull: noquirk policy:push 
not-client
Sep 20 18:11:53 djpc pluto[9618]: | phase 1 is done, looking for phase 1 
to unpend
Sep 20 18:11:53 djpc pluto[9618]: | next event EVENT_RETRANSMIT in 7 
seconds for #2
Sep 20 18:11:53 djpc pluto[9618]: |
Sep 20 18:11:53 djpc pluto[9618]: | *received 68 bytes from 
192.168.1.250:500 on eth0 (port=500)
Sep 20 18:11:53 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46  8d 38 1b 
33  f4 c5 e0 f4
Sep 20 18:11:53 djpc pluto[9618]: |   05 10 02 01  00 00 00 00  00 00 00 
44  56 dd 20 42
Sep 20 18:11:53 djpc pluto[9618]: |   8d 64 b2 8f  bf 18 48 e9  92 8a 3a 
e3  db 46 51 13
Sep 20 18:11:53 djpc pluto[9618]: |   e5 91 c9 a3  7b cb 11 df  ff 06 d9 
c5  bb 73 65 5b
Sep 20 18:11:53 djpc pluto[9618]: |   34 2e 67 a4
Sep 20 18:11:53 djpc pluto[9618]: | **parse ISAKMP Message:
Sep 20 18:11:53 djpc pluto[9618]: |    initiator cookie:
Sep 20 18:11:53 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:53 djpc pluto[9618]: |    responder cookie:
Sep 20 18:11:53 djpc pluto[9618]: |   8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:53 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_ID
Sep 20 18:11:53 djpc pluto[9618]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:11:53 djpc pluto[9618]: |    exchange type: ISAKMP_XCHG_IDPROT
Sep 20 18:11:53 djpc pluto[9618]: |    flags: ISAKMP_FLAG_ENCRYPTION
Sep 20 18:11:53 djpc pluto[9618]: |    message ID:  00 00 00 00
Sep 20 18:11:53 djpc pluto[9618]: |    length: 68
Sep 20 18:11:53 djpc pluto[9618]: |  processing packet with exchange 
type=ISAKMP_XCHG_IDPROT (2)
Sep 20 18:11:53 djpc pluto[9618]: | ICOOKIE:  a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:53 djpc pluto[9618]: | RCOOKIE:  8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:53 djpc pluto[9618]: | peer:  c0 a8 01 fa
Sep 20 18:11:53 djpc pluto[9618]: | state hash entry 0
Sep 20 18:11:53 djpc pluto[9618]: | peer and cookies match on #1, 
provided msgid 00000000 vs 00000000
Sep 20 18:11:53 djpc pluto[9618]: | state object #1 found, in STATE_MAIN_R2
Sep 20 18:11:53 djpc pluto[9618]: | processing connection L2TP-PSK
Sep 20 18:11:53 djpc pluto[9618]: | received encrypted packet from 
192.168.1.250:500
Sep 20 18:11:53 djpc pluto[9618]: | decrypting 40 bytes using algorithm 
OAKLEY_3DES_CBC
Sep 20 18:11:53 djpc pluto[9618]: | decrypted:
Sep 20 18:11:53 djpc pluto[9618]: |   08 00 00 0c  01 00 00 00  c0 a8 01 
fa  00 00 00 18
Sep 20 18:11:53 djpc pluto[9618]: |   b7 58 e9 33  03 6f 2b 26  72 95 b5 
0d  6f 89 87 8b
Sep 20 18:11:53 djpc pluto[9618]: |   2d 62 33 38  00 00 00 00
Sep 20 18:11:53 djpc pluto[9618]: | next IV:  bb 73 65 5b  34 2e 67 a4
Sep 20 18:11:53 djpc pluto[9618]: | ***parse ISAKMP Identification Payload:
Sep 20 18:11:53 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_HASH
Sep 20 18:11:53 djpc pluto[9618]: |    length: 12
Sep 20 18:11:53 djpc pluto[9618]: |    ID type: ID_IPV4_ADDR
Sep 20 18:11:53 djpc pluto[9618]: |    DOI specific A: 0
Sep 20 18:11:53 djpc pluto[9618]: |    DOI specific B: 0
Sep 20 18:11:53 djpc pluto[9618]: | ***parse ISAKMP Hash Payload:
Sep 20 18:11:53 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:11:53 djpc pluto[9618]: |    length: 24
Sep 20 18:11:53 djpc pluto[9618]: | removing 4 bytes of padding
Sep 20 18:11:53 djpc pluto[9618]: "L2TP-PSK" #1: Main mode peer ID is 
ID_IPV4_ADDR: '192.168.1.250'
Sep 20 18:11:53 djpc pluto[9618]: | refine_connection: starting with 
L2TP-PSK
Sep 20 18:11:53 djpc pluto[9618]: |   trusted_ca called with a=(empty) 
b=(empty)
Sep 20 18:11:53 djpc pluto[9618]: | refine_connection: happy with 
starting point: L2TP-PSK
Sep 20 18:11:53 djpc pluto[9618]: | offered CA: '%none'
Sep 20 18:11:53 djpc pluto[9618]: | hashing 196 bytes of SA
Sep 20 18:11:53 djpc pluto[9618]: | authentication succeeded
Sep 20 18:11:53 djpc pluto[9618]: | thinking about whether to send my 
certificate:
Sep 20 18:11:53 djpc pluto[9618]: |   I have RSA key: 
OAKLEY_PRESHARED_KEY cert.type: CERT_NONE
Sep 20 18:11:53 djpc pluto[9618]: |   sendcert: CERT_ALWAYSSEND and I 
did not get a certificate request
Sep 20 18:11:53 djpc pluto[9618]: |   so do not send cert.
Sep 20 18:11:53 djpc pluto[9618]: "L2TP-PSK" #1: I did not send a 
certificate because I do not have one.
Sep 20 18:11:53 djpc pluto[9618]: | **emit ISAKMP Message:
Sep 20 18:11:53 djpc pluto[9618]: |    initiator cookie:
Sep 20 18:11:53 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:53 djpc pluto[9618]: |    responder cookie:
Sep 20 18:11:53 djpc pluto[9618]: |   8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:53 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_ID
Sep 20 18:11:53 djpc pluto[9618]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:11:53 djpc pluto[9618]: |    exchange type: ISAKMP_XCHG_IDPROT
Sep 20 18:11:53 djpc pluto[9618]: |    flags: ISAKMP_FLAG_ENCRYPTION
Sep 20 18:11:53 djpc pluto[9618]: |    message ID:  00 00 00 00
Sep 20 18:11:53 djpc pluto[9618]: | ***emit ISAKMP Identification 
Payload (IPsec DOI):
Sep 20 18:11:53 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_HASH
Sep 20 18:11:53 djpc pluto[9618]: |    ID type: ID_IPV4_ADDR
Sep 20 18:11:53 djpc pluto[9618]: |    Protocol ID: 0
Sep 20 18:11:53 djpc pluto[9618]: |    port: 0
Sep 20 18:11:53 djpc pluto[9618]: | emitting 4 raw bytes of my identity 
into ISAKMP Identification Payload (IPsec DOI)
Sep 20 18:11:53 djpc pluto[9618]: | my identity  c0 a8 01 07
Sep 20 18:11:53 djpc pluto[9618]: | emitting length of ISAKMP 
Identification Payload (IPsec DOI): 12
Sep 20 18:11:53 djpc pluto[9618]: | hashing 196 bytes of SA
Sep 20 18:11:53 djpc pluto[9618]: | ***emit ISAKMP Hash Payload:
Sep 20 18:11:53 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:11:53 djpc pluto[9618]: | emitting 20 raw bytes of HASH_R into 
ISAKMP Hash Payload
Sep 20 18:11:53 djpc pluto[9618]: | HASH_R  cd e8 8a f9  f3 1c 75 7b  e9 
25 6e 77  94 6c 82 e2
Sep 20 18:11:53 djpc pluto[9618]: |   63 7e a2 66
Sep 20 18:11:53 djpc pluto[9618]: | emitting length of ISAKMP Hash 
Payload: 24
Sep 20 18:11:53 djpc pluto[9618]: | encrypting:
Sep 20 18:11:53 djpc pluto[9618]: |   08 00 00 0c  01 00 00 00  c0 a8 01 
07  00 00 00 18
Sep 20 18:11:53 djpc pluto[9618]: |   cd e8 8a f9  f3 1c 75 7b  e9 25 6e 
77  94 6c 82 e2
Sep 20 18:11:53 djpc pluto[9618]: |   63 7e a2 66
Sep 20 18:11:53 djpc pluto[9618]: | IV:
Sep 20 18:11:53 djpc pluto[9618]: |   bb 73 65 5b  34 2e 67 a4
Sep 20 18:11:53 djpc pluto[9618]: | emitting 4 zero bytes of encryption 
padding into ISAKMP Message
Sep 20 18:11:53 djpc pluto[9618]: | encrypting using OAKLEY_3DES_CBC
Sep 20 18:11:53 djpc pluto[9618]: | next IV:  87 83 9f 0f  4a b7 31 97
Sep 20 18:11:53 djpc pluto[9618]: | emitting length of ISAKMP Message: 68
Sep 20 18:11:53 djpc pluto[9618]: | last encrypted block of Phase 1:
Sep 20 18:11:53 djpc pluto[9618]: |   87 83 9f 0f  4a b7 31 97
Sep 20 18:11:53 djpc pluto[9618]: | complete state transition with STF_OK
Sep 20 18:11:54 djpc pluto[9618]: "L2TP-PSK" #1: transition from state 
STATE_MAIN_R2 to state STATE_MAIN_R3
Sep 20 18:11:54 djpc pluto[9618]: | sending reply packet to 
192.168.1.250:500 (from port=500)
Sep 20 18:11:54 djpc pluto[9618]: | sending 68 bytes for STATE_MAIN_R2 
through eth0:500 to 192.168.1.250:500:
Sep 20 18:11:54 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46  8d 38 1b 
33  f4 c5 e0 f4
Sep 20 18:11:54 djpc pluto[9618]: |   05 10 02 01  00 00 00 00  00 00 00 
44  0c 3d 4d 9a
Sep 20 18:11:54 djpc pluto[9618]: |   c3 68 f4 0e  72 b4 aa e6  63 aa bc 
31  f0 8a 74 3c
Sep 20 18:11:54 djpc pluto[9618]: |   26 39 37 fe  5d f6 d3 c1  fd 8a 5b 
2c  87 83 9f 0f
Sep 20 18:11:54 djpc pluto[9618]: |   4a b7 31 97
Sep 20 18:11:54 djpc pluto[9618]: | inserting event EVENT_SA_EXPIRE, 
timeout in 28800 seconds for #1
Sep 20 18:11:54 djpc pluto[9618]: "L2TP-PSK" #1: STATE_MAIN_R3: sent 
MR3, ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY 
cipher=oakley_3des_cbc_192 prf=oakley_sha group=modp2048}
Sep 20 18:11:54 djpc pluto[9618]: | modecfg pull: noquirk policy:push 
not-client
Sep 20 18:11:54 djpc pluto[9618]: | phase 1 is done, looking for phase 1 
to unpend
Sep 20 18:11:54 djpc pluto[9618]: | next event EVENT_RETRANSMIT in 5 
seconds for #2
Sep 20 18:11:54 djpc pluto[9618]: |
Sep 20 18:11:54 djpc pluto[9618]: | *received 68 bytes from 
192.168.1.250:500 on eth0 (port=500)
Sep 20 18:11:54 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46  8d 38 1b 
33  f4 c5 e0 f4
Sep 20 18:11:54 djpc pluto[9618]: |   05 10 02 01  00 00 00 00  00 00 00 
44  56 dd 20 42
Sep 20 18:11:54 djpc pluto[9618]: |   8d 64 b2 8f  bf 18 48 e9  92 8a 3a 
e3  db 46 51 13
Sep 20 18:11:54 djpc pluto[9618]: |   e5 91 c9 a3  7b cb 11 df  ff 06 d9 
c5  bb 73 65 5b
Sep 20 18:11:54 djpc pluto[9618]: |   34 2e 67 a4
Sep 20 18:11:54 djpc pluto[9618]: | **parse ISAKMP Message:
Sep 20 18:11:54 djpc pluto[9618]: |    initiator cookie:
Sep 20 18:11:54 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:54 djpc pluto[9618]: |    responder cookie:
Sep 20 18:11:54 djpc pluto[9618]: |   8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:54 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_ID
Sep 20 18:11:54 djpc pluto[9618]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:11:54 djpc pluto[9618]: |    exchange type: ISAKMP_XCHG_IDPROT
Sep 20 18:11:54 djpc pluto[9618]: |    flags: ISAKMP_FLAG_ENCRYPTION
Sep 20 18:11:54 djpc pluto[9618]: |    message ID:  00 00 00 00
Sep 20 18:11:54 djpc pluto[9618]: |    length: 68
Sep 20 18:11:54 djpc pluto[9618]: |  processing packet with exchange 
type=ISAKMP_XCHG_IDPROT (2)
Sep 20 18:11:54 djpc pluto[9618]: | ICOOKIE:  a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:54 djpc pluto[9618]: | RCOOKIE:  8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:54 djpc pluto[9618]: | peer:  c0 a8 01 fa
Sep 20 18:11:54 djpc pluto[9618]: | state hash entry 0
Sep 20 18:11:54 djpc pluto[9618]: | peer and cookies match on #1, 
provided msgid 00000000 vs 00000000
Sep 20 18:11:54 djpc pluto[9618]: | state object #1 found, in STATE_MAIN_R3
Sep 20 18:11:54 djpc pluto[9618]: | processing connection L2TP-PSK
Sep 20 18:11:54 djpc pluto[9618]: "L2TP-PSK" #1: retransmitting in 
response to duplicate packet; already STATE_MAIN_R3
Sep 20 18:11:54 djpc pluto[9618]: | sending 68 bytes for retransmit in 
response to duplicate through eth0:500 to 192.168.1.250:500:
Sep 20 18:11:54 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46  8d 38 1b 
33  f4 c5 e0 f4
Sep 20 18:11:54 djpc pluto[9618]: |   05 10 02 01  00 00 00 00  00 00 00 
44  0c 3d 4d 9a
Sep 20 18:11:54 djpc pluto[9618]: |   c3 68 f4 0e  72 b4 aa e6  63 aa bc 
31  f0 8a 74 3c
Sep 20 18:11:54 djpc pluto[9618]: |   26 39 37 fe  5d f6 d3 c1  fd 8a 5b 
2c  87 83 9f 0f
Sep 20 18:11:54 djpc pluto[9618]: |   4a b7 31 97
Sep 20 18:11:54 djpc pluto[9618]: | next event EVENT_RETRANSMIT in 5 
seconds for #2
Sep 20 18:11:54 djpc pluto[9618]: |
Sep 20 18:11:54 djpc pluto[9618]: | *received 1300 bytes from 
192.168.1.250:500 on eth0 (port=500)
Sep 20 18:11:54 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46  8d 38 1b 
33  f4 c5 e0 f4
Sep 20 18:11:54 djpc pluto[9618]: |   08 10 20 01  6c aa 7a e4  00 00 05 
14  d7 c7 ff cc
Sep 20 18:11:54 djpc pluto[9618]: |   aa 11 b0 fd  cb b5 35 d8  28 12 c4 
6f  5e 7b b2 4e
Sep 20 18:11:54 djpc pluto[9618]: |   31 32 06 92  89 8a 2f 13  ee 3a 21 
cb  d6 85 e2 b6
Sep 20 18:11:54 djpc pluto[9618]: |   22 7c 2d 03  c0 b5 8a c8  f3 11 ef 
3f  bf fe 4a 7a
Sep 20 18:11:54 djpc pluto[9618]: |   58 5b b4 3f  3b 12 bb 16  a1 21 51 
c3  cc a8 83 af
Sep 20 18:11:54 djpc pluto[9618]: |   8c a8 2f 60  fd 27 8c f1  e9 e7 9d 
24  d2 84 10 a6
Sep 20 18:11:54 djpc pluto[9618]: |   c4 90 70 e2  46 74 10 cd  7c 64 48 
7d  7f e6 89 f5
Sep 20 18:11:54 djpc pluto[9618]: |   54 c8 f8 99  e4 58 bb 46  04 cb 61 
de  2c 40 eb 29
Sep 20 18:11:54 djpc pluto[9618]: |   5d 08 0a 3b  dd 9e 3a de  dd 9a 39 
28  04 d5 d9 3a
Sep 20 18:11:54 djpc pluto[9618]: |   0d fe 5a 77  ac 3d 2e ce  24 3c 65 
66  c2 9c d6 ac
Sep 20 18:11:54 djpc pluto[9618]: |   e9 4a ef 3a  d4 5d c6 0d  9f 7f 63 
cc  70 05 8d c6
Sep 20 18:11:54 djpc pluto[9618]: |   b5 e5 03 2d  2b 4a d8 08  77 2b 53 
e5  9b c4 0d 30
Sep 20 18:11:54 djpc pluto[9618]: |   df c4 a6 89  ff 9c 6b ce  63 6f 9d 
20  52 f2 a2 a5
Sep 20 18:11:54 djpc pluto[9618]: |   a1 39 05 f1  96 9c 2e 42  83 83 ad 
f9  2e 05 91 13
Sep 20 18:11:54 djpc pluto[9618]: |   64 2b 21 9e  3b a2 57 eb  06 ba 5d 
29  50 11 ef 8c
Sep 20 18:11:54 djpc pluto[9618]: |   52 18 7d a8  f4 68 45 91  bc c0 d5 
ab  1e 8f 75 55
Sep 20 18:11:54 djpc pluto[9618]: |   8b 35 2b 07  00 29 ce 0d  3d f7 2d 
6b  ac 1a 03 70
Sep 20 18:11:54 djpc pluto[9618]: |   58 5b 54 99  65 0a ca d0  fc f0 c4 
b5  ca 63 bc 84
Sep 20 18:11:54 djpc pluto[9618]: |   5b fd 1e 1f  3f a1 a3 8d  e7 d4 39 
87  56 f6 40 17
Sep 20 18:11:54 djpc pluto[9618]: |   d0 53 c7 6e  15 e0 a3 e8  16 62 c2 
fd  9f 25 c9 85
Sep 20 18:11:54 djpc pluto[9618]: |   15 9d bb 31  6b 59 51 58  99 b3 2b 
86  de e6 6e dc
Sep 20 18:11:54 djpc pluto[9618]: |   3b 65 76 c3  a6 2d c5 fc  8c c9 e3 
69  2b c5 89 97
Sep 20 18:11:54 djpc pluto[9618]: |   0f 0a 8d 3d  c0 b4 0a aa  03 e9 33 
78  74 38 78 84
Sep 20 18:11:54 djpc pluto[9618]: |   79 dc a4 e8  47 dd 1c 69  bf b7 53 
51  50 11 1a 04
Sep 20 18:11:54 djpc pluto[9618]: |   85 18 bb f4  21 e8 96 00  af 99 34 
81  41 5e 77 62
Sep 20 18:11:54 djpc pluto[9618]: |   13 61 96 23  8d bf ff e9  8e f4 33 
e7  41 d7 0d ab
Sep 20 18:11:54 djpc pluto[9618]: |   a8 e6 89 e9  96 d9 7e 6b  6f 2b 55 
42  13 83 b1 40
Sep 20 18:11:54 djpc pluto[9618]: |   e7 c3 e5 ce  cf ec d3 3c  ee 60 38 
df  ab b2 66 a5
Sep 20 18:11:54 djpc pluto[9618]: |   56 0c e3 6b  3e 5a 87 c4  15 3b e4 
0a  ae 99 8f 5f
Sep 20 18:11:54 djpc pluto[9618]: |   67 19 3f ac  bb 98 03 74  38 3d 05 
f5  b5 18 2b 4d
Sep 20 18:11:54 djpc pluto[9618]: |   b1 27 c4 a8  a9 c9 76 de  04 80 61 
fb  c5 21 47 ae
Sep 20 18:11:54 djpc pluto[9618]: |   92 87 0f 20  49 f1 26 4d  1e 2b 8f 
5a  78 fc 12 8a
Sep 20 18:11:54 djpc pluto[9618]: |   6b 55 02 ce  c5 b0 64 0c  70 8a c1 
b0  b1 44 60 d7
Sep 20 18:11:54 djpc pluto[9618]: |   2d 8a 61 c0  24 15 cd 04  c1 bf 18 
eb  81 ab 01 8a
Sep 20 18:11:54 djpc pluto[9618]: |   82 3f 30 e0  36 07 4d 2a  5c ff 07 
51  fe ba 71 d3
Sep 20 18:11:54 djpc pluto[9618]: |   c9 f8 10 1e  d9 c7 71 fc  c8 6b da 
74  77 02 76 51
Sep 20 18:11:54 djpc pluto[9618]: |   7a 1d 2e 54  95 eb 6e f1  b6 d5 4c 
13  01 d5 a0 84
Sep 20 18:11:54 djpc pluto[9618]: |   19 3a 83 64  b4 aa b7 c2  a3 4b 80 
cd  19 3d a1 a9
Sep 20 18:11:54 djpc pluto[9618]: |   7c e9 21 24  55 4b 8a 34  66 bb 08 
ff  32 33 e1 68
Sep 20 18:11:54 djpc pluto[9618]: |   0f 42 5a 3a  11 1a c6 cf  9e 8c bc 
ec  ed e9 9f 49
Sep 20 18:11:54 djpc pluto[9618]: |   f4 b1 27 9c  75 0f 5d 41  26 1e 3c 
78  9e 09 c1 93
Sep 20 18:11:54 djpc pluto[9618]: |   a4 71 d1 b3  0e 33 6e 49  86 4d e0 
a3  ea cb ff b4
Sep 20 18:11:54 djpc pluto[9618]: |   04 c0 1c 51  44 3c f4 53  d8 f2 13 
5f  90 1f ea 61
Sep 20 18:11:54 djpc pluto[9618]: |   6e d5 d4 14  06 6c e8 ea  64 3b 33 
4e  c9 8a e6 4d
Sep 20 18:11:54 djpc pluto[9618]: |   ce 37 f7 84  18 01 79 40  d3 46 7b 
fb  cc d3 c9 3c
Sep 20 18:11:54 djpc pluto[9618]: |   83 16 04 cc  a6 fb d9 8c  08 18 38 
12  55 60 3b 3f
Sep 20 18:11:54 djpc pluto[9618]: |   74 1a 46 39  34 11 5d 4b  5f 42 94 
d3  af 41 61 26
Sep 20 18:11:55 djpc pluto[9618]: |   93 e2 6d da  14 68 70 0f  78 d6 32 
c7  51 dd c9 75
Sep 20 18:11:55 djpc pluto[9618]: |   94 20 43 82  f5 3e 28 f1  b8 cf b1 
0e  e8 e7 4d c3
Sep 20 18:11:55 djpc pluto[9618]: |   08 15 a8 39  98 4f 5d 68  92 e5 22 
1c  08 84 66 19
Sep 20 18:11:55 djpc pluto[9618]: |   4c 9f a2 cc  25 a3 cf ad  56 31 1b 
0a  24 fc 61 ff
Sep 20 18:11:55 djpc pluto[9618]: |   a9 f5 b2 36  ee bf 74 c5  88 2e 2b 
9c  d0 a6 73 b5
Sep 20 18:11:55 djpc pluto[9618]: |   b1 2a 75 46  32 20 b4 c2  39 2f 78 
6b  27 84 dc 74
Sep 20 18:11:55 djpc pluto[9618]: |   8e 0a a5 64  5d d6 96 9f  4a b4 75 
37  c0 6e 06 0e
Sep 20 18:11:55 djpc pluto[9618]: |   ac 8c 8a d2  e2 97 84 ed  d6 e2 19 
8e  0d 9d 68 0e
Sep 20 18:11:55 djpc pluto[9618]: |   03 c0 dc 2e  c8 20 64 73  83 77 41 
44  37 b4 3c 63
Sep 20 18:11:55 djpc pluto[9618]: |   5e d3 9b b0  14 d6 35 1c  af dd 3f 
a4  7c 38 3b 78
Sep 20 18:11:55 djpc pluto[9618]: |   77 2c ad c1  5a 42 ed ea  4b ee 4f 
5a  aa 1d 5c ae
Sep 20 18:11:55 djpc pluto[9618]: |   96 09 d2 91  66 38 00 26  cc 93 b2 
40  ca 75 f3 dc
Sep 20 18:11:55 djpc pluto[9618]: |   b0 d1 68 08  9f 96 fe 6b  87 91 45 
29  18 1e c7 82
Sep 20 18:11:55 djpc pluto[9618]: |   2b ad a0 bf  de 92 9d bb  d5 6b 15 
f6  01 5a d3 21
Sep 20 18:11:55 djpc pluto[9618]: |   b0 2b 6c f7  00 dc 52 ce  ea 69 87 
ff  37 dc aa c3
Sep 20 18:11:55 djpc pluto[9618]: |   10 cc d4 66  6f 5b 0b c2  7c c2 0f 
e2  e9 72 9e 50
Sep 20 18:11:55 djpc pluto[9618]: |   18 c9 f0 8f  af a2 bb 59  e1 da 32 
a4  ad b0 f9 06
Sep 20 18:11:55 djpc pluto[9618]: |   ce 85 36 ba  4b 51 c8 da  bc 20 2a 
32  a3 bb 86 de
Sep 20 18:11:55 djpc pluto[9618]: |   18 cd c9 79  5f a5 d1 c2  d7 09 56 
84  84 fc 1f 21
Sep 20 18:11:55 djpc pluto[9618]: |   d1 14 e6 1d  a5 cb bf 86  1d b1 c8 
53  44 05 e9 71
Sep 20 18:11:55 djpc pluto[9618]: |   57 3c ab bf  5b c7 1a 73  16 46 17 
76  13 56 54 85
Sep 20 18:11:55 djpc pluto[9618]: |   3c 43 7b 9c  f9 53 b6 09  85 ba d5 
71  6c 97 5c 89
Sep 20 18:11:55 djpc pluto[9618]: |   d2 a4 b9 15  8f 08 ac 75  8d 57 0b 
c8  b3 89 c6 29
Sep 20 18:11:55 djpc pluto[9618]: |   64 52 d6 9a  42 3d 0c c3  5a 58 05 
49  a1 a1 e6 3e
Sep 20 18:11:55 djpc pluto[9618]: |   11 8d eb fe  36 50 b1 82  19 1e 05 
d1  2c d5 05 5b
Sep 20 18:11:55 djpc pluto[9618]: |   c7 7b 62 b4  68 1b aa 97  c1 e1 61 
7e  8d cd 7a 45
Sep 20 18:11:55 djpc pluto[9618]: |   cc 9e 63 33  8e 9c 13 0b  8c e4 9b 
46  5b a3 31 70
Sep 20 18:11:55 djpc pluto[9618]: |   d3 0b 11 c0  7d b4 50 8a  1c d4 4f 
58  84 bb f4 ea
Sep 20 18:11:55 djpc pluto[9618]: |   bf 0d 5f 34  4c 5a 7a 6d  d0 f8 d6 
45  3d 50 39 0a
Sep 20 18:11:55 djpc pluto[9618]: |   af a3 e4 d3  df 85 c7 da  c2 e0 b5 
e0  a4 13 c0 1e
Sep 20 18:11:55 djpc pluto[9618]: |   25 1d 5c f4  bb 39 85 2e  a3 b9 4a 
9e  b6 f1 8b 5e
Sep 20 18:11:55 djpc pluto[9618]: |   f0 ef da aa  2f ff a6 8c  19 e0 08 
0d  19 e5 72 ff
Sep 20 18:11:55 djpc pluto[9618]: |   28 47 a2 54  cc df c2 4d  2e 4c ea 
ea  f7 29 1f 9c
Sep 20 18:11:55 djpc pluto[9618]: |   0c dd a8 02
Sep 20 18:11:55 djpc pluto[9618]: | **parse ISAKMP Message:
Sep 20 18:11:55 djpc pluto[9618]: |    initiator cookie:
Sep 20 18:11:55 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:55 djpc pluto[9618]: |    responder cookie:
Sep 20 18:11:55 djpc pluto[9618]: |   8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:55 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_HASH
Sep 20 18:11:55 djpc pluto[9618]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:11:55 djpc pluto[9618]: |    exchange type: ISAKMP_XCHG_QUICK
Sep 20 18:11:55 djpc pluto[9618]: |    flags: ISAKMP_FLAG_ENCRYPTION
Sep 20 18:11:55 djpc pluto[9618]: |    message ID:  6c aa 7a e4
Sep 20 18:11:55 djpc pluto[9618]: |    length: 1300
Sep 20 18:11:55 djpc pluto[9618]: |  processing packet with exchange 
type=ISAKMP_XCHG_QUICK (32)
Sep 20 18:11:55 djpc pluto[9618]: | ICOOKIE:  a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:55 djpc pluto[9618]: | RCOOKIE:  8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:55 djpc pluto[9618]: | peer:  c0 a8 01 fa
Sep 20 18:11:55 djpc pluto[9618]: | state hash entry 0
Sep 20 18:11:55 djpc pluto[9618]: | peer and cookies match on #1, 
provided msgid 6caa7ae4 vs 00000000
Sep 20 18:11:55 djpc pluto[9618]: | state object not found
Sep 20 18:11:55 djpc pluto[9618]: | ICOOKIE:  a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:55 djpc pluto[9618]: | RCOOKIE:  8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:55 djpc pluto[9618]: | peer:  c0 a8 01 fa
Sep 20 18:11:55 djpc pluto[9618]: | state hash entry 0
Sep 20 18:11:55 djpc pluto[9618]: | peer and cookies match on #1, 
provided msgid 00000000 vs 00000000
Sep 20 18:11:55 djpc pluto[9618]: | state object #1 found, in STATE_MAIN_R3
Sep 20 18:11:55 djpc pluto[9618]: | processing connection L2TP-PSK
Sep 20 18:11:55 djpc pluto[9618]: | last Phase 1 IV:  87 83 9f 0f  4a b7 
31 97
Sep 20 18:11:55 djpc pluto[9618]: | current Phase 1 IV:  87 83 9f 0f  4a 
b7 31 97
Sep 20 18:11:55 djpc pluto[9618]: | computed Phase 2 IV:
Sep 20 18:11:55 djpc pluto[9618]: |   8e 16 09 76  c2 08 d6 3e  a1 a0 70 
53  d3 bd e9 2d
Sep 20 18:11:55 djpc pluto[9618]: |   af 95 ec 9b
Sep 20 18:11:55 djpc pluto[9618]: | received encrypted packet from 
192.168.1.250:500
Sep 20 18:11:55 djpc pluto[9618]: | decrypting 1272 bytes using 
algorithm OAKLEY_3DES_CBC
Sep 20 18:11:55 djpc pluto[9618]: | decrypted:
Sep 20 18:11:55 djpc pluto[9618]: |   01 00 00 18  e0 51 cf 92  3b 8a 0c 
86  a6 8a 98 86
Sep 20 18:11:55 djpc pluto[9618]: |   77 31 0b 89  3f 8a 26 a4  0a 00 04 
ac  00 00 00 01
Sep 20 18:11:55 djpc pluto[9618]: |   00 00 00 01  02 00 00 5c  01 03 04 
02  46 eb 69 03
Sep 20 18:11:55 djpc pluto[9618]: |   03 00 00 28  01 03 00 00  80 01 00 
01  00 02 00 04
Sep 20 18:11:55 djpc pluto[9618]: |   00 00 0e 10  80 01 00 02  00 02 00 
04  00 03 d0 90
Sep 20 18:11:55 djpc pluto[9618]: |   80 04 00 02  80 05 00 01  00 00 00 
28  02 03 00 00
Sep 20 18:11:55 djpc pluto[9618]: |   80 01 00 01  00 02 00 04  00 00 0e 
10  80 01 00 02
Sep 20 18:11:55 djpc pluto[9618]: |   00 02 00 04  00 03 d0 90  80 04 00 
02  80 05 00 02
Sep 20 18:11:55 djpc pluto[9618]: |   02 00 00 34  02 02 04 01  46 eb 69 
03  00 00 00 28
Sep 20 18:11:55 djpc pluto[9618]: |   01 03 00 00  80 01 00 01  00 02 00 
04  00 00 0e 10
Sep 20 18:11:55 djpc pluto[9618]: |   80 01 00 02  00 02 00 04  00 03 d0 
90  80 04 00 02
Sep 20 18:11:55 djpc pluto[9618]: |   80 05 00 02  02 00 00 30  02 03 04 
01  74 ac 45 c1
Sep 20 18:11:55 djpc pluto[9618]: |   00 00 00 24  01 03 00 00  80 01 00 
01  00 02 00 04
Sep 20 18:11:55 djpc pluto[9618]: |   00 00 0e 10  80 01 00 02  00 02 00 
04  00 03 d0 90
Sep 20 18:11:55 djpc pluto[9618]: |   80 04 00 02  02 00 00 34  03 02 04 
01  46 eb 69 03
Sep 20 18:11:55 djpc pluto[9618]: |   00 00 00 28  01 02 00 00  80 01 00 
01  00 02 00 04
Sep 20 18:11:55 djpc pluto[9618]: |   00 00 0e 10  80 01 00 02  00 02 00 
04  00 03 d0 90
Sep 20 18:11:55 djpc pluto[9618]: |   80 04 00 02  80 05 00 01  02 00 00 
30  03 03 04 01
Sep 20 18:11:55 djpc pluto[9618]: |   74 ac 45 c1  00 00 00 24  01 03 00 
00  80 01 00 01
Sep 20 18:11:55 djpc pluto[9618]: |   00 02 00 04  00 00 0e 10  80 01 00 
02  00 02 00 04
Sep 20 18:11:55 djpc pluto[9618]: |   00 03 d0 90  80 04 00 02  02 00 00 
34  04 02 04 01
Sep 20 18:11:55 djpc pluto[9618]: |   46 eb 69 03  00 00 00 28  01 03 00 
00  80 01 00 01
Sep 20 18:11:55 djpc pluto[9618]: |   00 02 00 04  00 00 0e 10  80 01 00 
02  00 02 00 04
Sep 20 18:11:55 djpc pluto[9618]: |   00 03 d0 90  80 04 00 02  80 05 00 
02  02 00 00 34
Sep 20 18:11:55 djpc pluto[9618]: |   04 03 04 01  74 ac 45 c1  00 00 00 
28  01 03 00 00
Sep 20 18:11:55 djpc pluto[9618]: |   80 01 00 01  00 02 00 04  00 00 0e 
10  80 01 00 02
Sep 20 18:11:55 djpc pluto[9618]: |   00 02 00 04  00 03 d0 90  80 04 00 
02  80 05 00 02
Sep 20 18:11:55 djpc pluto[9618]: |   02 00 00 34  05 02 04 01  46 eb 69 
03  00 00 00 28
Sep 20 18:11:55 djpc pluto[9618]: |   01 02 00 00  80 01 00 01  00 02 00 
04  00 00 0e 10
Sep 20 18:11:56 djpc pluto[9618]: |   80 01 00 02  00 02 00 04  00 03 d0 
90  80 04 00 02
Sep 20 18:11:56 djpc pluto[9618]: |   80 05 00 01  02 00 00 34  05 03 04 
01  74 ac 45 c1
Sep 20 18:11:56 djpc pluto[9618]: |   00 00 00 28  01 03 00 00  80 01 00 
01  00 02 00 04
Sep 20 18:11:56 djpc pluto[9618]: |   00 00 0e 10  80 01 00 02  00 02 00 
04  00 03 d0 90
Sep 20 18:11:56 djpc pluto[9618]: |   80 04 00 02  80 05 00 01  02 00 00 
5c  06 03 04 02
Sep 20 18:11:56 djpc pluto[9618]: |   46 eb 69 03  03 00 00 28  01 02 00 
00  80 01 00 01
Sep 20 18:11:56 djpc pluto[9618]: |   00 02 00 04  00 00 0e 10  80 01 00 
02  00 02 00 04
Sep 20 18:11:56 djpc pluto[9618]: |   00 03 d0 90  80 04 00 02  80 05 00 
01  00 00 00 28
Sep 20 18:11:56 djpc pluto[9618]: |   02 02 00 00  80 01 00 01  00 02 00 
04  00 00 0e 10
Sep 20 18:11:56 djpc pluto[9618]: |   80 01 00 02  00 02 00 04  00 03 d0 
90  80 04 00 02
Sep 20 18:11:56 djpc pluto[9618]: |   80 05 00 02  02 00 00 34  07 02 04 
01  46 eb 69 03
Sep 20 18:11:56 djpc pluto[9618]: |   00 00 00 28  01 03 00 00  80 01 00 
01  00 02 00 04
Sep 20 18:11:56 djpc pluto[9618]: |   00 00 0e 10  80 01 00 02  00 02 00 
04  00 03 d0 90
Sep 20 18:11:56 djpc pluto[9618]: |   80 04 00 02  80 05 00 02  02 00 00 
30  07 03 04 01
Sep 20 18:11:56 djpc pluto[9618]: |   74 ac 45 c1  00 00 00 24  01 02 00 
00  80 01 00 01
Sep 20 18:11:56 djpc pluto[9618]: |   00 02 00 04  00 00 0e 10  80 01 00 
02  00 02 00 04
Sep 20 18:11:56 djpc pluto[9618]: |   00 03 d0 90  80 04 00 02  02 00 00 
34  08 02 04 01
Sep 20 18:11:56 djpc pluto[9618]: |   46 eb 69 03  00 00 00 28  01 02 00 
00  80 01 00 01
Sep 20 18:11:56 djpc pluto[9618]: |   00 02 00 04  00 00 0e 10  80 01 00 
02  00 02 00 04
Sep 20 18:11:56 djpc pluto[9618]: |   00 03 d0 90  80 04 00 02  80 05 00 
01  02 00 00 30
Sep 20 18:11:56 djpc pluto[9618]: |   08 03 04 01  74 ac 45 c1  00 00 00 
24  01 02 00 00
Sep 20 18:11:56 djpc pluto[9618]: |   80 01 00 01  00 02 00 04  00 00 0e 
10  80 01 00 02
Sep 20 18:11:56 djpc pluto[9618]: |   00 02 00 04  00 03 d0 90  80 04 00 
02  02 00 00 34
Sep 20 18:11:56 djpc pluto[9618]: |   09 02 04 01  46 eb 69 03  00 00 00 
28  01 03 00 00
Sep 20 18:11:56 djpc pluto[9618]: |   80 01 00 01  00 02 00 04  00 00 0e 
10  80 01 00 02
Sep 20 18:11:56 djpc pluto[9618]: |   00 02 00 04  00 03 d0 90  80 04 00 
02  80 05 00 02
Sep 20 18:11:56 djpc pluto[9618]: |   02 00 00 34  09 03 04 01  74 ac 45 
c1  00 00 00 28
Sep 20 18:11:56 djpc pluto[9618]: |   01 02 00 00  80 01 00 01  00 02 00 
04  00 00 0e 10
Sep 20 18:11:56 djpc pluto[9618]: |   80 01 00 02  00 02 00 04  00 03 d0 
90  80 04 00 02
Sep 20 18:11:56 djpc pluto[9618]: |   80 05 00 02  02 00 00 34  0a 02 04 
01  46 eb 69 03
Sep 20 18:11:56 djpc pluto[9618]: |   00 00 00 28  01 02 00 00  80 01 00 
01  00 02 00 04
Sep 20 18:11:56 djpc pluto[9618]: |   00 00 0e 10  80 01 00 02  00 02 00 
04  00 03 d0 90
Sep 20 18:11:56 djpc pluto[9618]: |   80 04 00 02  80 05 00 01  02 00 00 
34  0a 03 04 01
Sep 20 18:11:56 djpc pluto[9618]: |   74 ac 45 c1  00 00 00 28  01 02 00 
00  80 01 00 01
Sep 20 18:11:56 djpc pluto[9618]: |   00 02 00 04  00 00 0e 10  80 01 00 
02  00 02 00 04
Sep 20 18:11:56 djpc pluto[9618]: |   00 03 d0 90  80 04 00 02  80 05 00 
01  02 00 00 5c
Sep 20 18:11:56 djpc pluto[9618]: |   0b 03 04 02  46 eb 69 03  03 00 00 
28  01 0b 00 00
Sep 20 18:11:56 djpc pluto[9618]: |   80 01 00 01  00 02 00 04  00 00 0e 
10  80 01 00 02
Sep 20 18:11:56 djpc pluto[9618]: |   00 02 00 04  00 03 d0 90  80 04 00 
02  80 05 00 02
Sep 20 18:11:56 djpc pluto[9618]: |   00 00 00 28  02 0b 00 00  80 01 00 
01  00 02 00 04
Sep 20 18:11:56 djpc pluto[9618]: |   00 00 0e 10  80 01 00 02  00 02 00 
04  00 03 d0 90
Sep 20 18:11:56 djpc pluto[9618]: |   80 04 00 02  80 05 00 01  00 00 00 
5c  0c 02 04 02
Sep 20 18:11:56 djpc pluto[9618]: |   46 eb 69 03  03 00 00 28  01 03 00 
00  80 01 00 01
Sep 20 18:11:56 djpc pluto[9618]: |   00 02 00 04  00 00 0e 10  80 01 00 
02  00 02 00 04
Sep 20 18:11:56 djpc pluto[9618]: |   00 03 d0 90  80 04 00 02  80 05 00 
02  00 00 00 28
Sep 20 18:11:56 djpc pluto[9618]: |   02 02 00 00  80 01 00 01  00 02 00 
04  00 00 0e 10
Sep 20 18:11:56 djpc pluto[9618]: |   80 01 00 02  00 02 00 04  00 03 d0 
90  80 04 00 02
Sep 20 18:11:56 djpc pluto[9618]: |   80 05 00 01  05 00 00 18  c6 83 f5 
15  b3 ea 8c a3
Sep 20 18:11:56 djpc pluto[9618]: |   10 7d bb c9  9a c5 53 a2  6b 66 f6 
af  05 00 00 0c
Sep 20 18:11:56 djpc pluto[9618]: |   01 11 06 a5  c0 a8 01 fa  00 00 00 
0c  01 11 06 a5
Sep 20 18:11:56 djpc pluto[9618]: |   c0 a8 01 07  00 00 00 00
Sep 20 18:11:56 djpc pluto[9618]: | next IV:  f7 29 1f 9c  0c dd a8 02
Sep 20 18:11:56 djpc pluto[9618]: | ***parse ISAKMP Hash Payload:
Sep 20 18:11:56 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_SA
Sep 20 18:11:56 djpc pluto[9618]: |    length: 24
Sep 20 18:11:56 djpc pluto[9618]: | ***parse ISAKMP Security Association 
Payload:
Sep 20 18:11:56 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONCE
Sep 20 18:11:56 djpc pluto[9618]: |    length: 1196
Sep 20 18:11:56 djpc pluto[9618]: |    DOI: ISAKMP_DOI_IPSEC
Sep 20 18:11:56 djpc pluto[9618]: | ***parse ISAKMP Nonce Payload:
Sep 20 18:11:56 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_ID
Sep 20 18:11:56 djpc pluto[9618]: |    length: 24
Sep 20 18:11:56 djpc pluto[9618]: | ***parse ISAKMP Identification 
Payload (IPsec DOI):
Sep 20 18:11:56 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_ID
Sep 20 18:11:56 djpc pluto[9618]: |    length: 12
Sep 20 18:11:56 djpc pluto[9618]: |    ID type: ID_IPV4_ADDR
Sep 20 18:11:56 djpc pluto[9618]: |    Protocol ID: 17
Sep 20 18:11:56 djpc pluto[9618]: |    port: 1701
Sep 20 18:11:56 djpc pluto[9618]: | ***parse ISAKMP Identification 
Payload (IPsec DOI):
Sep 20 18:11:56 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:11:56 djpc pluto[9618]: |    length: 12
Sep 20 18:11:56 djpc pluto[9618]: |    ID type: ID_IPV4_ADDR
Sep 20 18:11:56 djpc pluto[9618]: |    Protocol ID: 17
Sep 20 18:11:56 djpc pluto[9618]: |    port: 1701
Sep 20 18:11:56 djpc pluto[9618]: | removing 4 bytes of padding
Sep 20 18:11:56 djpc pluto[9618]: | HASH(1) computed:
Sep 20 18:11:56 djpc pluto[9618]: |   e0 51 cf 92  3b 8a 0c 86  a6 8a 98 
86  77 31 0b 89
Sep 20 18:11:56 djpc pluto[9618]: |   3f 8a 26 a4
Sep 20 18:11:56 djpc pluto[9618]: | peer client is 192.168.1.250
Sep 20 18:11:56 djpc pluto[9618]: | peer client protocol/port is 17/1701
Sep 20 18:11:56 djpc pluto[9618]: | our client is 192.168.1.7
Sep 20 18:11:56 djpc pluto[9618]: | our client protocol/port is 17/1701
Sep 20 18:11:56 djpc pluto[9618]: | find_client_connection starting with 
L2TP-PSK
Sep 20 18:11:56 djpc pluto[9618]: |   looking for 192.168.1.7/32:17/1701 
-> 192.168.1.250/32:17/1701
Sep 20 18:11:56 djpc pluto[9618]: |   concrete checking against sr#0 
192.168.1.7/32 -> 192.168.1.250/32
Sep 20 18:11:56 djpc pluto[9618]: |    match_id a=192.168.1.250
Sep 20 18:11:56 djpc pluto[9618]: |             b=192.168.1.250
Sep 20 18:11:56 djpc pluto[9618]: |    results  matched
Sep 20 18:11:56 djpc pluto[9618]: |   trusted_ca called with a=(empty) 
b=(empty)
Sep 20 18:11:56 djpc pluto[9618]: |   fc_try trying 
L2TP-PSK:192.168.1.7/32:17/1701 -> 192.168.1.250/32:17/0 vs 
L2TP-PSK:192.168.1.7/32:17/1701 -> 192.168.1.250/32:17/0
Sep 20 18:11:56 djpc pluto[9618]: |   fc_try concluding with L2TP-PSK [128]
Sep 20 18:11:56 djpc pluto[9618]: |   fc_try L2TP-PSK gives L2TP-PSK
Sep 20 18:11:56 djpc pluto[9618]: |   concluding with d = L2TP-PSK
Sep 20 18:11:56 djpc pluto[9618]: | duplicating state object #1
Sep 20 18:11:56 djpc pluto[9618]: | creating state object #3 at 0x80ff3c8
Sep 20 18:11:56 djpc pluto[9618]: | processing connection L2TP-PSK
Sep 20 18:11:56 djpc pluto[9618]: | ICOOKIE:  a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:56 djpc pluto[9618]: | RCOOKIE:  8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:57 djpc pluto[9618]: | peer:  c0 a8 01 fa
Sep 20 18:11:57 djpc pluto[9618]: | state hash entry 0
Sep 20 18:11:57 djpc pluto[9618]: | inserting event EVENT_SO_DISCARD, 
timeout in 0 seconds for #3
Sep 20 18:11:57 djpc pluto[9618]: | ****parse IPsec DOI SIT:
Sep 20 18:11:57 djpc pluto[9618]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Sep 20 18:11:57 djpc pluto[9618]: | ****parse ISAKMP Proposal Payload:
Sep 20 18:11:57 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_P
Sep 20 18:11:57 djpc pluto[9618]: |    length: 92
Sep 20 18:11:57 djpc pluto[9618]: |    proposal number: 1
Sep 20 18:11:57 djpc pluto[9618]: |    protocol ID: PROTO_IPSEC_ESP
Sep 20 18:11:57 djpc pluto[9618]: |    SPI size: 4
Sep 20 18:11:57 djpc pluto[9618]: |    number of transforms: 2
Sep 20 18:11:57 djpc pluto[9618]: | parsing 4 raw bytes of ISAKMP 
Proposal Payload into SPI
Sep 20 18:11:57 djpc pluto[9618]: | SPI  46 eb 69 03
Sep 20 18:11:57 djpc pluto[9618]: | ****parse ISAKMP Proposal Payload:
Sep 20 18:11:57 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_P
Sep 20 18:11:57 djpc pluto[9618]: |    length: 52
Sep 20 18:11:57 djpc pluto[9618]: |    proposal number: 2
Sep 20 18:11:57 djpc pluto[9618]: |    protocol ID: PROTO_IPSEC_AH
Sep 20 18:11:57 djpc pluto[9618]: |    SPI size: 4
Sep 20 18:11:57 djpc pluto[9618]: |    number of transforms: 1
Sep 20 18:11:57 djpc pluto[9618]: | *****parse ISAKMP Transform Payload 
(ESP):
Sep 20 18:11:57 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_T
Sep 20 18:11:57 djpc pluto[9618]: |    length: 40
Sep 20 18:11:57 djpc pluto[9618]: |    transform number: 1
Sep 20 18:11:57 djpc pluto[9618]: |    transform ID: ESP_3DES
Sep 20 18:11:57 djpc pluto[9618]: | ******parse ISAKMP IPsec DOI attribute:
Sep 20 18:11:57 djpc pluto[9618]: |    af+type: SA_LIFE_TYPE
Sep 20 18:11:57 djpc pluto[9618]: |    length/value: 1
Sep 20 18:11:57 djpc pluto[9618]: |    [1 is SA_LIFE_TYPE_SECONDS]
Sep 20 18:11:57 djpc pluto[9618]: | ******parse ISAKMP IPsec DOI attribute:
Sep 20 18:11:57 djpc pluto[9618]: |    af+type: SA_LIFE_DURATION 
(variable length)
Sep 20 18:11:57 djpc pluto[9618]: |    length/value: 4
Sep 20 18:11:57 djpc pluto[9618]: |    long duration: 3600
Sep 20 18:11:57 djpc pluto[9618]: | ******parse ISAKMP IPsec DOI attribute:
Sep 20 18:11:57 djpc pluto[9618]: |    af+type: SA_LIFE_TYPE
Sep 20 18:11:57 djpc pluto[9618]: |    length/value: 2
Sep 20 18:11:57 djpc pluto[9618]: |    [2 is SA_LIFE_TYPE_KBYTES]
Sep 20 18:11:57 djpc pluto[9618]: | ******parse ISAKMP IPsec DOI attribute:
Sep 20 18:11:57 djpc pluto[9618]: |    af+type: SA_LIFE_DURATION 
(variable length)
Sep 20 18:11:57 djpc pluto[9618]: |    length/value: 4
Sep 20 18:11:57 djpc pluto[9618]: |    long duration: 250000
Sep 20 18:11:57 djpc pluto[9618]: | ******parse ISAKMP IPsec DOI attribute:
Sep 20 18:11:57 djpc pluto[9618]: |    af+type: ENCAPSULATION_MODE
Sep 20 18:11:57 djpc pluto[9618]: |    length/value: 2
Sep 20 18:11:57 djpc pluto[9618]: |    [2 is ENCAPSULATION_MODE_TRANSPORT]
Sep 20 18:11:57 djpc pluto[9618]: | ******parse ISAKMP IPsec DOI attribute:
Sep 20 18:11:57 djpc pluto[9618]: |    af+type: AUTH_ALGORITHM
Sep 20 18:11:57 djpc pluto[9618]: |    length/value: 1
Sep 20 18:11:57 djpc pluto[9618]: |    [1 is AUTH_ALGORITHM_HMAC_MD5]
Sep 20 18:11:57 djpc pluto[9618]: | 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
Sep 20 18:11:57 djpc pluto[9618]: | asking helper 0 to do build_nonce op 
on seq: 2
Sep 20 18:11:57 djpc pluto[9618]: | inserting event EVENT_CRYPTO_FAILED, 
timeout in 300 seconds for #3
Sep 20 18:11:57 djpc pluto[9649]: ! helper -1 doing build_nonce op id: 2
Sep 20 18:11:57 djpc pluto[9618]: | complete state transition with 
STF_SUSPEND
Sep 20 18:11:57 djpc pluto[9649]: ! Generated nonce:
Sep 20 18:11:57 djpc pluto[9618]: | next event EVENT_RETRANSMIT in 2 
seconds for #2
Sep 20 18:11:57 djpc pluto[9649]: !   56 fe 1f 87  dc 23 ca 30  c7 ab 2c 
71  7f 91 8c da
Sep 20 18:11:57 djpc pluto[9618]: |
Sep 20 18:11:57 djpc pluto[9618]: | *received 1300 bytes from 
192.168.1.250:500 on eth0 (port=500)
Sep 20 18:11:57 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46  8d 38 1b 
33  f4 c5 e0 f4
Sep 20 18:11:57 djpc pluto[9618]: |   08 10 20 01  6c aa 7a e4  00 00 05 
14  d7 c7 ff cc
Sep 20 18:11:57 djpc pluto[9618]: |   aa 11 b0 fd  cb b5 35 d8  28 12 c4 
6f  5e 7b b2 4e
Sep 20 18:11:57 djpc pluto[9618]: |   31 32 06 92  89 8a 2f 13  ee 3a 21 
cb  d6 85 e2 b6
Sep 20 18:11:57 djpc pluto[9618]: |   22 7c 2d 03  c0 b5 8a c8  f3 11 ef 
3f  bf fe 4a 7a
Sep 20 18:11:57 djpc pluto[9618]: |   58 5b b4 3f  3b 12 bb 16  a1 21 51 
c3  cc a8 83 af
Sep 20 18:11:57 djpc pluto[9618]: |   8c a8 2f 60  fd 27 8c f1  e9 e7 9d 
24  d2 84 10 a6
Sep 20 18:11:57 djpc pluto[9618]: |   c4 90 70 e2  46 74 10 cd  7c 64 48 
7d  7f e6 89 f5
Sep 20 18:11:57 djpc pluto[9618]: |   54 c8 f8 99  e4 58 bb 46  04 cb 61 
de  2c 40 eb 29
Sep 20 18:11:57 djpc pluto[9618]: |   5d 08 0a 3b  dd 9e 3a de  dd 9a 39 
28  04 d5 d9 3a
Sep 20 18:11:57 djpc pluto[9618]: |   0d fe 5a 77  ac 3d 2e ce  24 3c 65 
66  c2 9c d6 ac
Sep 20 18:11:57 djpc pluto[9618]: |   e9 4a ef 3a  d4 5d c6 0d  9f 7f 63 
cc  70 05 8d c6
Sep 20 18:11:57 djpc pluto[9618]: |   b5 e5 03 2d  2b 4a d8 08  77 2b 53 
e5  9b c4 0d 30
Sep 20 18:11:57 djpc pluto[9618]: |   df c4 a6 89  ff 9c 6b ce  63 6f 9d 
20  52 f2 a2 a5
Sep 20 18:11:57 djpc pluto[9618]: |   a1 39 05 f1  96 9c 2e 42  83 83 ad 
f9  2e 05 91 13
Sep 20 18:11:57 djpc pluto[9618]: |   64 2b 21 9e  3b a2 57 eb  06 ba 5d 
29  50 11 ef 8c
Sep 20 18:11:57 djpc pluto[9618]: |   52 18 7d a8  f4 68 45 91  bc c0 d5 
ab  1e 8f 75 55
Sep 20 18:11:57 djpc pluto[9618]: |   8b 35 2b 07  00 29 ce 0d  3d f7 2d 
6b  ac 1a 03 70
Sep 20 18:11:57 djpc pluto[9618]: |   58 5b 54 99  65 0a ca d0  fc f0 c4 
b5  ca 63 bc 84
Sep 20 18:11:57 djpc pluto[9618]: |   5b fd 1e 1f  3f a1 a3 8d  e7 d4 39 
87  56 f6 40 17
Sep 20 18:11:57 djpc pluto[9618]: |   d0 53 c7 6e  15 e0 a3 e8  16 62 c2 
fd  9f 25 c9 85
Sep 20 18:11:57 djpc pluto[9618]: |   15 9d bb 31  6b 59 51 58  99 b3 2b 
86  de e6 6e dc
Sep 20 18:11:57 djpc pluto[9618]: |   3b 65 76 c3  a6 2d c5 fc  8c c9 e3 
69  2b c5 89 97
Sep 20 18:11:57 djpc pluto[9618]: |   0f 0a 8d 3d  c0 b4 0a aa  03 e9 33 
78  74 38 78 84
Sep 20 18:11:57 djpc pluto[9618]: |   79 dc a4 e8  47 dd 1c 69  bf b7 53 
51  50 11 1a 04
Sep 20 18:11:57 djpc pluto[9618]: |   85 18 bb f4  21 e8 96 00  af 99 34 
81  41 5e 77 62
Sep 20 18:11:57 djpc pluto[9618]: |   13 61 96 23  8d bf ff e9  8e f4 33 
e7  41 d7 0d ab
Sep 20 18:11:57 djpc pluto[9618]: |   a8 e6 89 e9  96 d9 7e 6b  6f 2b 55 
42  13 83 b1 40
Sep 20 18:11:57 djpc pluto[9618]: |   e7 c3 e5 ce  cf ec d3 3c  ee 60 38 
df  ab b2 66 a5
Sep 20 18:11:57 djpc pluto[9618]: |   56 0c e3 6b  3e 5a 87 c4  15 3b e4 
0a  ae 99 8f 5f
Sep 20 18:11:57 djpc pluto[9618]: |   67 19 3f ac  bb 98 03 74  38 3d 05 
f5  b5 18 2b 4d
Sep 20 18:11:57 djpc pluto[9618]: |   b1 27 c4 a8  a9 c9 76 de  04 80 61 
fb  c5 21 47 ae
Sep 20 18:11:57 djpc pluto[9618]: |   92 87 0f 20  49 f1 26 4d  1e 2b 8f 
5a  78 fc 12 8a
Sep 20 18:11:57 djpc pluto[9618]: |   6b 55 02 ce  c5 b0 64 0c  70 8a c1 
b0  b1 44 60 d7
Sep 20 18:11:57 djpc pluto[9618]: |   2d 8a 61 c0  24 15 cd 04  c1 bf 18 
eb  81 ab 01 8a
Sep 20 18:11:57 djpc pluto[9618]: |   82 3f 30 e0  36 07 4d 2a  5c ff 07 
51  fe ba 71 d3
Sep 20 18:11:57 djpc pluto[9618]: |   c9 f8 10 1e  d9 c7 71 fc  c8 6b da 
74  77 02 76 51
Sep 20 18:11:57 djpc pluto[9618]: |   7a 1d 2e 54  95 eb 6e f1  b6 d5 4c 
13  01 d5 a0 84
Sep 20 18:11:57 djpc pluto[9618]: |   19 3a 83 64  b4 aa b7 c2  a3 4b 80 
cd  19 3d a1 a9
Sep 20 18:11:57 djpc pluto[9618]: |   7c e9 21 24  55 4b 8a 34  66 bb 08 
ff  32 33 e1 68
Sep 20 18:11:57 djpc pluto[9618]: |   0f 42 5a 3a  11 1a c6 cf  9e 8c bc 
ec  ed e9 9f 49
Sep 20 18:11:58 djpc pluto[9618]: |   f4 b1 27 9c  75 0f 5d 41  26 1e 3c 
78  9e 09 c1 93
Sep 20 18:11:58 djpc pluto[9618]: |   a4 71 d1 b3  0e 33 6e 49  86 4d e0 
a3  ea cb ff b4
Sep 20 18:11:58 djpc pluto[9618]: |   04 c0 1c 51  44 3c f4 53  d8 f2 13 
5f  90 1f ea 61
Sep 20 18:11:58 djpc pluto[9618]: |   6e d5 d4 14  06 6c e8 ea  64 3b 33 
4e  c9 8a e6 4d
Sep 20 18:11:58 djpc pluto[9618]: |   ce 37 f7 84  18 01 79 40  d3 46 7b 
fb  cc d3 c9 3c
Sep 20 18:11:58 djpc pluto[9618]: |   83 16 04 cc  a6 fb d9 8c  08 18 38 
12  55 60 3b 3f
Sep 20 18:11:58 djpc pluto[9618]: |   74 1a 46 39  34 11 5d 4b  5f 42 94 
d3  af 41 61 26
Sep 20 18:11:58 djpc pluto[9618]: |   93 e2 6d da  14 68 70 0f  78 d6 32 
c7  51 dd c9 75
Sep 20 18:11:58 djpc pluto[9618]: |   94 20 43 82  f5 3e 28 f1  b8 cf b1 
0e  e8 e7 4d c3
Sep 20 18:11:58 djpc pluto[9618]: |   08 15 a8 39  98 4f 5d 68  92 e5 22 
1c  08 84 66 19
Sep 20 18:11:58 djpc pluto[9618]: |   4c 9f a2 cc  25 a3 cf ad  56 31 1b 
0a  24 fc 61 ff
Sep 20 18:11:58 djpc pluto[9618]: |   a9 f5 b2 36  ee bf 74 c5  88 2e 2b 
9c  d0 a6 73 b5
Sep 20 18:11:58 djpc pluto[9618]: |   b1 2a 75 46  32 20 b4 c2  39 2f 78 
6b  27 84 dc 74
Sep 20 18:11:58 djpc pluto[9618]: |   8e 0a a5 64  5d d6 96 9f  4a b4 75 
37  c0 6e 06 0e
Sep 20 18:11:58 djpc pluto[9618]: |   ac 8c 8a d2  e2 97 84 ed  d6 e2 19 
8e  0d 9d 68 0e
Sep 20 18:11:58 djpc pluto[9618]: |   03 c0 dc 2e  c8 20 64 73  83 77 41 
44  37 b4 3c 63
Sep 20 18:11:58 djpc pluto[9618]: |   5e d3 9b b0  14 d6 35 1c  af dd 3f 
a4  7c 38 3b 78
Sep 20 18:11:58 djpc pluto[9618]: |   77 2c ad c1  5a 42 ed ea  4b ee 4f 
5a  aa 1d 5c ae
Sep 20 18:11:58 djpc pluto[9618]: |   96 09 d2 91  66 38 00 26  cc 93 b2 
40  ca 75 f3 dc
Sep 20 18:11:58 djpc pluto[9618]: |   b0 d1 68 08  9f 96 fe 6b  87 91 45 
29  18 1e c7 82
Sep 20 18:11:58 djpc pluto[9618]: |   2b ad a0 bf  de 92 9d bb  d5 6b 15 
f6  01 5a d3 21
Sep 20 18:11:58 djpc pluto[9618]: |   b0 2b 6c f7  00 dc 52 ce  ea 69 87 
ff  37 dc aa c3
Sep 20 18:11:58 djpc pluto[9618]: |   10 cc d4 66  6f 5b 0b c2  7c c2 0f 
e2  e9 72 9e 50
Sep 20 18:11:58 djpc pluto[9618]: |   18 c9 f0 8f  af a2 bb 59  e1 da 32 
a4  ad b0 f9 06
Sep 20 18:11:58 djpc pluto[9618]: |   ce 85 36 ba  4b 51 c8 da  bc 20 2a 
32  a3 bb 86 de
Sep 20 18:11:58 djpc pluto[9618]: |   18 cd c9 79  5f a5 d1 c2  d7 09 56 
84  84 fc 1f 21
Sep 20 18:11:58 djpc pluto[9618]: |   d1 14 e6 1d  a5 cb bf 86  1d b1 c8 
53  44 05 e9 71
Sep 20 18:11:58 djpc pluto[9618]: |   57 3c ab bf  5b c7 1a 73  16 46 17 
76  13 56 54 85
Sep 20 18:11:58 djpc pluto[9618]: |   3c 43 7b 9c  f9 53 b6 09  85 ba d5 
71  6c 97 5c 89
Sep 20 18:11:58 djpc pluto[9618]: |   d2 a4 b9 15  8f 08 ac 75  8d 57 0b 
c8  b3 89 c6 29
Sep 20 18:11:58 djpc pluto[9618]: |   64 52 d6 9a  42 3d 0c c3  5a 58 05 
49  a1 a1 e6 3e
Sep 20 18:11:58 djpc pluto[9618]: |   11 8d eb fe  36 50 b1 82  19 1e 05 
d1  2c d5 05 5b
Sep 20 18:11:58 djpc pluto[9618]: |   c7 7b 62 b4  68 1b aa 97  c1 e1 61 
7e  8d cd 7a 45
Sep 20 18:11:58 djpc pluto[9618]: |   cc 9e 63 33  8e 9c 13 0b  8c e4 9b 
46  5b a3 31 70
Sep 20 18:11:58 djpc pluto[9618]: |   d3 0b 11 c0  7d b4 50 8a  1c d4 4f 
58  84 bb f4 ea
Sep 20 18:11:58 djpc pluto[9618]: |   bf 0d 5f 34  4c 5a 7a 6d  d0 f8 d6 
45  3d 50 39 0a
Sep 20 18:11:58 djpc pluto[9618]: |   af a3 e4 d3  df 85 c7 da  c2 e0 b5 
e0  a4 13 c0 1e
Sep 20 18:11:58 djpc pluto[9618]: |   25 1d 5c f4  bb 39 85 2e  a3 b9 4a 
9e  b6 f1 8b 5e
Sep 20 18:11:58 djpc pluto[9618]: |   f0 ef da aa  2f ff a6 8c  19 e0 08 
0d  19 e5 72 ff
Sep 20 18:11:58 djpc pluto[9618]: |   28 47 a2 54  cc df c2 4d  2e 4c ea 
ea  f7 29 1f 9c
Sep 20 18:11:58 djpc pluto[9618]: |   0c dd a8 02
Sep 20 18:11:58 djpc pluto[9618]: | **parse ISAKMP Message:
Sep 20 18:11:58 djpc pluto[9618]: |    initiator cookie:
Sep 20 18:11:58 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:58 djpc pluto[9618]: |    responder cookie:
Sep 20 18:11:58 djpc pluto[9618]: |   8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:58 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_HASH
Sep 20 18:11:58 djpc pluto[9618]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:11:58 djpc pluto[9618]: |    exchange type: ISAKMP_XCHG_QUICK
Sep 20 18:11:58 djpc pluto[9618]: |    flags: ISAKMP_FLAG_ENCRYPTION
Sep 20 18:11:58 djpc pluto[9618]: |    message ID:  6c aa 7a e4
Sep 20 18:11:58 djpc pluto[9618]: |    length: 1300
Sep 20 18:11:58 djpc pluto[9618]: |  processing packet with exchange 
type=ISAKMP_XCHG_QUICK (32)
Sep 20 18:11:58 djpc pluto[9618]: | ICOOKIE:  a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:58 djpc pluto[9618]: | RCOOKIE:  8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:58 djpc pluto[9618]: | peer:  c0 a8 01 fa
Sep 20 18:11:58 djpc pluto[9618]: | state hash entry 0
Sep 20 18:11:58 djpc pluto[9618]: | peer and cookies match on #3, 
provided msgid 6caa7ae4 vs 6caa7ae4
Sep 20 18:11:58 djpc pluto[9618]: | state object #3 found, in STATE_QUICK_R0
Sep 20 18:11:58 djpc pluto[9618]: | processing connection L2TP-PSK
Sep 20 18:11:58 djpc pluto[9618]: "L2TP-PSK" #3: message received while 
calculating. Ignored.
Sep 20 18:11:58 djpc pluto[9618]: | next event EVENT_RETRANSMIT in 1 
seconds for #2
Sep 20 18:11:58 djpc pluto[9618]: |
Sep 20 18:11:58 djpc pluto[9618]: | *received 1300 bytes from 
192.168.1.250:500 on eth0 (port=500)
Sep 20 18:11:58 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46  8d 38 1b 
33  f4 c5 e0 f4
Sep 20 18:11:58 djpc pluto[9618]: |   08 10 20 01  6c aa 7a e4  00 00 05 
14  d7 c7 ff cc
Sep 20 18:11:58 djpc pluto[9618]: |   aa 11 b0 fd  cb b5 35 d8  28 12 c4 
6f  5e 7b b2 4e
Sep 20 18:11:58 djpc pluto[9618]: |   31 32 06 92  89 8a 2f 13  ee 3a 21 
cb  d6 85 e2 b6
Sep 20 18:11:58 djpc pluto[9618]: |   22 7c 2d 03  c0 b5 8a c8  f3 11 ef 
3f  bf fe 4a 7a
Sep 20 18:11:58 djpc pluto[9618]: |   58 5b b4 3f  3b 12 bb 16  a1 21 51 
c3  cc a8 83 af
Sep 20 18:11:58 djpc pluto[9618]: |   8c a8 2f 60  fd 27 8c f1  e9 e7 9d 
24  d2 84 10 a6
Sep 20 18:11:58 djpc pluto[9618]: |   c4 90 70 e2  46 74 10 cd  7c 64 48 
7d  7f e6 89 f5
Sep 20 18:11:58 djpc pluto[9618]: |   54 c8 f8 99  e4 58 bb 46  04 cb 61 
de  2c 40 eb 29
Sep 20 18:11:58 djpc pluto[9618]: |   5d 08 0a 3b  dd 9e 3a de  dd 9a 39 
28  04 d5 d9 3a
Sep 20 18:11:58 djpc pluto[9618]: |   0d fe 5a 77  ac 3d 2e ce  24 3c 65 
66  c2 9c d6 ac
Sep 20 18:11:58 djpc pluto[9618]: |   e9 4a ef 3a  d4 5d c6 0d  9f 7f 63 
cc  70 05 8d c6
Sep 20 18:11:58 djpc pluto[9618]: |   b5 e5 03 2d  2b 4a d8 08  77 2b 53 
e5  9b c4 0d 30
Sep 20 18:11:58 djpc pluto[9618]: |   df c4 a6 89  ff 9c 6b ce  63 6f 9d 
20  52 f2 a2 a5
Sep 20 18:11:58 djpc pluto[9618]: |   a1 39 05 f1  96 9c 2e 42  83 83 ad 
f9  2e 05 91 13
Sep 20 18:11:58 djpc pluto[9618]: |   64 2b 21 9e  3b a2 57 eb  06 ba 5d 
29  50 11 ef 8c
Sep 20 18:11:58 djpc pluto[9618]: |   52 18 7d a8  f4 68 45 91  bc c0 d5 
ab  1e 8f 75 55
Sep 20 18:11:58 djpc pluto[9618]: |   8b 35 2b 07  00 29 ce 0d  3d f7 2d 
6b  ac 1a 03 70
Sep 20 18:11:58 djpc pluto[9618]: |   58 5b 54 99  65 0a ca d0  fc f0 c4 
b5  ca 63 bc 84
Sep 20 18:11:58 djpc pluto[9618]: |   5b fd 1e 1f  3f a1 a3 8d  e7 d4 39 
87  56 f6 40 17
Sep 20 18:11:58 djpc pluto[9618]: |   d0 53 c7 6e  15 e0 a3 e8  16 62 c2 
fd  9f 25 c9 85
Sep 20 18:11:58 djpc pluto[9618]: |   15 9d bb 31  6b 59 51 58  99 b3 2b 
86  de e6 6e dc
Sep 20 18:11:58 djpc pluto[9618]: |   3b 65 76 c3  a6 2d c5 fc  8c c9 e3 
69  2b c5 89 97
Sep 20 18:11:58 djpc pluto[9618]: |   0f 0a 8d 3d  c0 b4 0a aa  03 e9 33 
78  74 38 78 84
Sep 20 18:11:58 djpc pluto[9618]: |   79 dc a4 e8  47 dd 1c 69  bf b7 53 
51  50 11 1a 04
Sep 20 18:11:58 djpc pluto[9618]: |   85 18 bb f4  21 e8 96 00  af 99 34 
81  41 5e 77 62
Sep 20 18:11:58 djpc pluto[9618]: |   13 61 96 23  8d bf ff e9  8e f4 33 
e7  41 d7 0d ab
Sep 20 18:11:58 djpc pluto[9618]: |   a8 e6 89 e9  96 d9 7e 6b  6f 2b 55 
42  13 83 b1 40
Sep 20 18:11:58 djpc pluto[9618]: |   e7 c3 e5 ce  cf ec d3 3c  ee 60 38 
df  ab b2 66 a5
Sep 20 18:11:58 djpc pluto[9618]: |   56 0c e3 6b  3e 5a 87 c4  15 3b e4 
0a  ae 99 8f 5f
Sep 20 18:11:58 djpc pluto[9618]: |   67 19 3f ac  bb 98 03 74  38 3d 05 
f5  b5 18 2b 4d
Sep 20 18:11:58 djpc pluto[9618]: |   b1 27 c4 a8  a9 c9 76 de  04 80 61 
fb  c5 21 47 ae
Sep 20 18:11:58 djpc pluto[9618]: |   92 87 0f 20  49 f1 26 4d  1e 2b 8f 
5a  78 fc 12 8a
Sep 20 18:11:58 djpc pluto[9618]: |   6b 55 02 ce  c5 b0 64 0c  70 8a c1 
b0  b1 44 60 d7
Sep 20 18:11:58 djpc pluto[9618]: |   2d 8a 61 c0  24 15 cd 04  c1 bf 18 
eb  81 ab 01 8a
Sep 20 18:11:58 djpc pluto[9618]: |   82 3f 30 e0  36 07 4d 2a  5c ff 07 
51  fe ba 71 d3
Sep 20 18:11:58 djpc pluto[9618]: |   c9 f8 10 1e  d9 c7 71 fc  c8 6b da 
74  77 02 76 51
Sep 20 18:11:59 djpc pluto[9618]: |   7a 1d 2e 54  95 eb 6e f1  b6 d5 4c 
13  01 d5 a0 84
Sep 20 18:11:59 djpc pluto[9618]: |   19 3a 83 64  b4 aa b7 c2  a3 4b 80 
cd  19 3d a1 a9
Sep 20 18:11:59 djpc pluto[9618]: |   7c e9 21 24  55 4b 8a 34  66 bb 08 
ff  32 33 e1 68
Sep 20 18:11:59 djpc pluto[9618]: |   0f 42 5a 3a  11 1a c6 cf  9e 8c bc 
ec  ed e9 9f 49
Sep 20 18:11:59 djpc pluto[9618]: |   f4 b1 27 9c  75 0f 5d 41  26 1e 3c 
78  9e 09 c1 93
Sep 20 18:11:59 djpc pluto[9618]: |   a4 71 d1 b3  0e 33 6e 49  86 4d e0 
a3  ea cb ff b4
Sep 20 18:11:59 djpc pluto[9618]: |   04 c0 1c 51  44 3c f4 53  d8 f2 13 
5f  90 1f ea 61
Sep 20 18:11:59 djpc pluto[9618]: |   6e d5 d4 14  06 6c e8 ea  64 3b 33 
4e  c9 8a e6 4d
Sep 20 18:11:59 djpc pluto[9618]: |   ce 37 f7 84  18 01 79 40  d3 46 7b 
fb  cc d3 c9 3c
Sep 20 18:11:59 djpc pluto[9618]: |   83 16 04 cc  a6 fb d9 8c  08 18 38 
12  55 60 3b 3f
Sep 20 18:11:59 djpc pluto[9618]: |   74 1a 46 39  34 11 5d 4b  5f 42 94 
d3  af 41 61 26
Sep 20 18:11:59 djpc pluto[9618]: |   93 e2 6d da  14 68 70 0f  78 d6 32 
c7  51 dd c9 75
Sep 20 18:11:59 djpc pluto[9618]: |   94 20 43 82  f5 3e 28 f1  b8 cf b1 
0e  e8 e7 4d c3
Sep 20 18:11:59 djpc pluto[9618]: |   08 15 a8 39  98 4f 5d 68  92 e5 22 
1c  08 84 66 19
Sep 20 18:11:59 djpc pluto[9618]: |   4c 9f a2 cc  25 a3 cf ad  56 31 1b 
0a  24 fc 61 ff
Sep 20 18:11:59 djpc pluto[9618]: |   a9 f5 b2 36  ee bf 74 c5  88 2e 2b 
9c  d0 a6 73 b5
Sep 20 18:11:59 djpc pluto[9618]: |   b1 2a 75 46  32 20 b4 c2  39 2f 78 
6b  27 84 dc 74
Sep 20 18:11:59 djpc pluto[9618]: |   8e 0a a5 64  5d d6 96 9f  4a b4 75 
37  c0 6e 06 0e
Sep 20 18:11:59 djpc pluto[9618]: |   ac 8c 8a d2  e2 97 84 ed  d6 e2 19 
8e  0d 9d 68 0e
Sep 20 18:11:59 djpc pluto[9618]: |   03 c0 dc 2e  c8 20 64 73  83 77 41 
44  37 b4 3c 63
Sep 20 18:11:59 djpc pluto[9618]: |   5e d3 9b b0  14 d6 35 1c  af dd 3f 
a4  7c 38 3b 78
Sep 20 18:11:59 djpc pluto[9618]: |   77 2c ad c1  5a 42 ed ea  4b ee 4f 
5a  aa 1d 5c ae
Sep 20 18:11:59 djpc pluto[9618]: |   96 09 d2 91  66 38 00 26  cc 93 b2 
40  ca 75 f3 dc
Sep 20 18:11:59 djpc pluto[9618]: |   b0 d1 68 08  9f 96 fe 6b  87 91 45 
29  18 1e c7 82
Sep 20 18:11:59 djpc pluto[9618]: |   2b ad a0 bf  de 92 9d bb  d5 6b 15 
f6  01 5a d3 21
Sep 20 18:11:59 djpc pluto[9618]: |   b0 2b 6c f7  00 dc 52 ce  ea 69 87 
ff  37 dc aa c3
Sep 20 18:11:59 djpc pluto[9618]: |   10 cc d4 66  6f 5b 0b c2  7c c2 0f 
e2  e9 72 9e 50
Sep 20 18:11:59 djpc pluto[9618]: |   18 c9 f0 8f  af a2 bb 59  e1 da 32 
a4  ad b0 f9 06
Sep 20 18:11:59 djpc pluto[9618]: |   ce 85 36 ba  4b 51 c8 da  bc 20 2a 
32  a3 bb 86 de
Sep 20 18:11:59 djpc pluto[9618]: |   18 cd c9 79  5f a5 d1 c2  d7 09 56 
84  84 fc 1f 21
Sep 20 18:11:59 djpc pluto[9618]: |   d1 14 e6 1d  a5 cb bf 86  1d b1 c8 
53  44 05 e9 71
Sep 20 18:11:59 djpc pluto[9618]: |   57 3c ab bf  5b c7 1a 73  16 46 17 
76  13 56 54 85
Sep 20 18:11:59 djpc pluto[9618]: |   3c 43 7b 9c  f9 53 b6 09  85 ba d5 
71  6c 97 5c 89
Sep 20 18:11:59 djpc pluto[9618]: |   d2 a4 b9 15  8f 08 ac 75  8d 57 0b 
c8  b3 89 c6 29
Sep 20 18:11:59 djpc pluto[9618]: |   64 52 d6 9a  42 3d 0c c3  5a 58 05 
49  a1 a1 e6 3e
Sep 20 18:11:59 djpc pluto[9618]: |   11 8d eb fe  36 50 b1 82  19 1e 05 
d1  2c d5 05 5b
Sep 20 18:11:59 djpc pluto[9618]: |   c7 7b 62 b4  68 1b aa 97  c1 e1 61 
7e  8d cd 7a 45
Sep 20 18:11:59 djpc pluto[9618]: |   cc 9e 63 33  8e 9c 13 0b  8c e4 9b 
46  5b a3 31 70
Sep 20 18:11:59 djpc pluto[9618]: |   d3 0b 11 c0  7d b4 50 8a  1c d4 4f 
58  84 bb f4 ea
Sep 20 18:11:59 djpc pluto[9618]: |   bf 0d 5f 34  4c 5a 7a 6d  d0 f8 d6 
45  3d 50 39 0a
Sep 20 18:11:59 djpc pluto[9618]: |   af a3 e4 d3  df 85 c7 da  c2 e0 b5 
e0  a4 13 c0 1e
Sep 20 18:11:59 djpc pluto[9618]: |   25 1d 5c f4  bb 39 85 2e  a3 b9 4a 
9e  b6 f1 8b 5e
Sep 20 18:11:59 djpc pluto[9618]: |   f0 ef da aa  2f ff a6 8c  19 e0 08 
0d  19 e5 72 ff
Sep 20 18:11:59 djpc pluto[9618]: |   28 47 a2 54  cc df c2 4d  2e 4c ea 
ea  f7 29 1f 9c
Sep 20 18:11:59 djpc pluto[9618]: |   0c dd a8 02
Sep 20 18:11:59 djpc pluto[9618]: | **parse ISAKMP Message:
Sep 20 18:11:59 djpc pluto[9618]: |    initiator cookie:
Sep 20 18:11:59 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:59 djpc pluto[9618]: |    responder cookie:
Sep 20 18:11:59 djpc pluto[9618]: |   8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:59 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_HASH
Sep 20 18:11:59 djpc pluto[9618]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:11:59 djpc pluto[9618]: |    exchange type: ISAKMP_XCHG_QUICK
Sep 20 18:11:59 djpc pluto[9618]: |    flags: ISAKMP_FLAG_ENCRYPTION
Sep 20 18:11:59 djpc pluto[9618]: |    message ID:  6c aa 7a e4
Sep 20 18:11:59 djpc pluto[9618]: |    length: 1300
Sep 20 18:11:59 djpc pluto[9618]: |  processing packet with exchange 
type=ISAKMP_XCHG_QUICK (32)
Sep 20 18:11:59 djpc pluto[9618]: | ICOOKIE:  a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:59 djpc pluto[9618]: | RCOOKIE:  8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:59 djpc pluto[9618]: | peer:  c0 a8 01 fa
Sep 20 18:11:59 djpc pluto[9618]: | state hash entry 0
Sep 20 18:11:59 djpc pluto[9618]: | peer and cookies match on #3, 
provided msgid 6caa7ae4 vs 6caa7ae4
Sep 20 18:11:59 djpc pluto[9618]: | state object #3 found, in STATE_QUICK_R0
Sep 20 18:11:59 djpc pluto[9618]: | processing connection L2TP-PSK
Sep 20 18:11:59 djpc pluto[9618]: "L2TP-PSK" #3: message received while 
calculating. Ignored.
Sep 20 18:11:59 djpc pluto[9618]: | helper 0 has work (cnt now 0)
Sep 20 18:11:59 djpc pluto[9618]: | helper 0 replies to sequence 2
Sep 20 18:11:59 djpc pluto[9618]: | calling callback function 0x8069d25
Sep 20 18:11:59 djpc pluto[9618]: | quick inI1_outR1: calculated 
ke+nonce, sending R1
Sep 20 18:11:59 djpc pluto[9618]: | processing connection L2TP-PSK
Sep 20 18:11:59 djpc pluto[9618]: | **emit ISAKMP Message:
Sep 20 18:11:59 djpc pluto[9618]: |    initiator cookie:
Sep 20 18:11:59 djpc pluto[9618]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:11:59 djpc pluto[9618]: |    responder cookie:
Sep 20 18:11:59 djpc pluto[9618]: |   8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:11:59 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_HASH
Sep 20 18:11:59 djpc pluto[9618]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:11:59 djpc pluto[9618]: |    exchange type: ISAKMP_XCHG_QUICK
Sep 20 18:11:59 djpc pluto[9618]: |    flags: ISAKMP_FLAG_ENCRYPTION
Sep 20 18:11:59 djpc pluto[9618]: |    message ID:  6c aa 7a e4
Sep 20 18:11:59 djpc pluto[9618]: | ***emit ISAKMP Hash Payload:
Sep 20 18:11:59 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_SA
Sep 20 18:11:59 djpc pluto[9618]: | emitting 20 zero bytes of HASH into 
ISAKMP Hash Payload
Sep 20 18:11:59 djpc pluto[9618]: | emitting length of ISAKMP Hash 
Payload: 24
Sep 20 18:11:59 djpc pluto[9618]: | ***emit ISAKMP Security Association 
Payload:
Sep 20 18:11:59 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONCE
Sep 20 18:11:59 djpc pluto[9618]: |    DOI: ISAKMP_DOI_IPSEC
Sep 20 18:11:59 djpc pluto[9618]: | ****parse IPsec DOI SIT:
Sep 20 18:11:59 djpc pluto[9618]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Sep 20 18:11:59 djpc pluto[9618]: | ****parse ISAKMP Proposal Payload:
Sep 20 18:11:59 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_P
Sep 20 18:11:59 djpc pluto[9618]: |    length: 92
Sep 20 18:11:59 djpc pluto[9618]: |    proposal number: 1
Sep 20 18:12:00 djpc pluto[9618]: |    protocol ID: PROTO_IPSEC_ESP
Sep 20 18:12:00 djpc pluto[9618]: |    SPI size: 4
Sep 20 18:12:00 djpc pluto[9618]: |    number of transforms: 2
Sep 20 18:12:00 djpc pluto[9618]: | parsing 4 raw bytes of ISAKMP 
Proposal Payload into SPI
Sep 20 18:12:00 djpc pluto[9618]: | SPI  46 eb 69 03
Sep 20 18:12:00 djpc pluto[9618]: | ****parse ISAKMP Proposal Payload:
Sep 20 18:12:00 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_P
Sep 20 18:12:00 djpc pluto[9618]: |    length: 52
Sep 20 18:12:00 djpc pluto[9618]: |    proposal number: 2
Sep 20 18:12:00 djpc pluto[9618]: |    protocol ID: PROTO_IPSEC_AH
Sep 20 18:12:00 djpc pluto[9618]: |    SPI size: 4
Sep 20 18:12:00 djpc pluto[9618]: |    number of transforms: 1
Sep 20 18:12:00 djpc pluto[9618]: | *****parse ISAKMP Transform Payload 
(ESP):
Sep 20 18:12:00 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_T
Sep 20 18:12:00 djpc pluto[9618]: |    length: 40
Sep 20 18:12:00 djpc pluto[9618]: |    transform number: 1
Sep 20 18:12:00 djpc pluto[9618]: |    transform ID: ESP_3DES
Sep 20 18:12:00 djpc pluto[9618]: | ******parse ISAKMP IPsec DOI attribute:
Sep 20 18:12:00 djpc pluto[9618]: |    af+type: SA_LIFE_TYPE
Sep 20 18:12:00 djpc pluto[9618]: |    length/value: 1
Sep 20 18:12:00 djpc pluto[9618]: |    [1 is SA_LIFE_TYPE_SECONDS]
Sep 20 18:12:00 djpc pluto[9618]: | ******parse ISAKMP IPsec DOI attribute:
Sep 20 18:12:00 djpc pluto[9618]: |    af+type: SA_LIFE_DURATION 
(variable length)
Sep 20 18:12:00 djpc pluto[9618]: |    length/value: 4
Sep 20 18:12:00 djpc pluto[9618]: |    long duration: 3600
Sep 20 18:12:00 djpc pluto[9618]: | ******parse ISAKMP IPsec DOI attribute:
Sep 20 18:12:00 djpc pluto[9618]: |    af+type: SA_LIFE_TYPE
Sep 20 18:12:00 djpc pluto[9618]: |    length/value: 2
Sep 20 18:12:00 djpc pluto[9618]: |    [2 is SA_LIFE_TYPE_KBYTES]
Sep 20 18:12:00 djpc pluto[9618]: | ******parse ISAKMP IPsec DOI attribute:
Sep 20 18:12:00 djpc pluto[9618]: |    af+type: SA_LIFE_DURATION 
(variable length)
Sep 20 18:12:00 djpc pluto[9618]: |    length/value: 4
Sep 20 18:12:00 djpc pluto[9618]: |    long duration: 250000
Sep 20 18:12:00 djpc pluto[9618]: | ******parse ISAKMP IPsec DOI attribute:
Sep 20 18:12:00 djpc pluto[9618]: |    af+type: ENCAPSULATION_MODE
Sep 20 18:12:00 djpc pluto[9618]: |    length/value: 2
Sep 20 18:12:00 djpc pluto[9618]: |    [2 is ENCAPSULATION_MODE_TRANSPORT]
Sep 20 18:12:00 djpc pluto[9618]: | ******parse ISAKMP IPsec DOI attribute:
Sep 20 18:12:00 djpc pluto[9618]: |    af+type: AUTH_ALGORITHM
Sep 20 18:12:00 djpc pluto[9618]: |    length/value: 1
Sep 20 18:12:00 djpc pluto[9618]: |    [1 is AUTH_ALGORITHM_HMAC_MD5]
Sep 20 18:12:00 djpc pluto[9618]: | ****emit IPsec DOI SIT:
Sep 20 18:12:00 djpc pluto[9618]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Sep 20 18:12:00 djpc pluto[9618]: | ****emit ISAKMP Proposal Payload:
Sep 20 18:12:00 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:12:00 djpc pluto[9618]: |    proposal number: 1
Sep 20 18:12:00 djpc pluto[9618]: |    protocol ID: PROTO_IPSEC_ESP
Sep 20 18:12:00 djpc pluto[9618]: |    SPI size: 4
Sep 20 18:12:00 djpc pluto[9618]: |    number of transforms: 1
Sep 20 18:12:00 djpc pluto[9618]: | netlink_get_spi: allocated 0x1ce1f4b 
for esp.0@192.168.1.7
Sep 20 18:12:00 djpc pluto[9618]: | emitting 4 raw bytes of SPI into 
ISAKMP Proposal Payload
Sep 20 18:12:00 djpc pluto[9618]: | SPI  01 ce 1f 4b
Sep 20 18:12:00 djpc pluto[9618]: | *****emit ISAKMP Transform Payload 
(ESP):
Sep 20 18:12:00 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_NONE
Sep 20 18:12:00 djpc pluto[9618]: |    transform number: 1
Sep 20 18:12:00 djpc pluto[9618]: |    transform ID: ESP_3DES
Sep 20 18:12:00 djpc pluto[9618]: | emitting 32 raw bytes of attributes 
into ISAKMP Transform Payload (ESP)
Sep 20 18:12:00 djpc pluto[9618]: | attributes  80 01 00 01  00 02 00 04 
  00 00 0e 10  80 01 00 02
Sep 20 18:12:00 djpc pluto[9618]: |   00 02 00 04  00 03 d0 90  80 04 00 
02  80 05 00 01
Sep 20 18:12:00 djpc pluto[9618]: | emitting length of ISAKMP Transform 
Payload (ESP): 40
Sep 20 18:12:00 djpc pluto[9618]: | emitting length of ISAKMP Proposal 
Payload: 52
Sep 20 18:12:00 djpc pluto[9618]: | emitting length of ISAKMP Security 
Association Payload: 64
Sep 20 18:12:00 djpc pluto[9618]: "L2TP-PSK" #3: responding to Quick 
Mode {msgid:e47aaa6c}
Sep 20 18:12:00 djpc pluto[9618]: | ***emit ISAKMP Nonce Payload:
Sep 20 18:12:00 djpc pluto[9618]: |    next payload type: ISAKMP_NEXT_ID
Sep 20 18:12:00 djpc pluto[9618]: | emitting 16 raw bytes of Nr into 
ISAKMP Nonce Payload
Sep 20 18:12:00 djpc pluto[9618]: | Nr  56 fe 1f 87  dc 23 ca 30  c7 ab 
2c 71  7f 91 8c da
Sep 20 18:12:00 djpc pluto[9618]: | emitting length of ISAKMP Nonce 
Payload: 20
Sep 20 18:12:00 djpc pluto[9618]: | emitting 12 raw bytes of IDci into 
ISAKMP Message
Sep 20 18:12:00 djpc pluto[9618]: | IDci  05 00 00 0c  01 11 06 a5  c0 
a8 01 fa
Sep 20 18:12:00 djpc pluto[9618]: | emitting 12 raw bytes of IDcr into 
ISAKMP Message
Sep 20 18:12:00 djpc pluto[9618]: | IDcr  00 00 00 0c  01 11 06 a5  c0 
a8 01 07
Sep 20 18:12:00 djpc pluto[9618]: | HASH(2) computed:
Sep 20 18:12:00 djpc pluto[9618]: |   32 c7 16 86  6d 2e d9 e6  31 9e cf 
6a  ee 28 eb 5d
Sep 20 18:12:00 djpc pluto[9618]: |   d7 f5 0a 1b
Sep 20 18:12:00 djpc pluto[9618]: | compute_proto_keymat:needed_len 
(after ESP enc)=24
Sep 20 18:12:00 djpc pluto[9618]: | compute_proto_keymat:needed_len 
(after ESP auth)=40
Sep 20 18:12:00 djpc pluto[9618]: | KEYMAT computed:
Sep 20 18:12:00 djpc pluto[9618]: |   05 1b 58 96  f4 dd 7c 55  57 65 1b 
8d  05 f2 3c 7e
Sep 20 18:12:00 djpc pluto[9618]: |   e8 bd 7e fa  bb 76 1f e3  e5 2d f3 
3a  da 54 2c 79
Sep 20 18:12:00 djpc pluto[9618]: |   81 e0 f0 92  b0 7c 25 25
Sep 20 18:12:00 djpc pluto[9618]: | Peer KEYMAT computed:
Sep 20 18:12:00 djpc pluto[9618]: |   ff 5f 40 9f  b1 bd e2 5d  6c 35 fa 
da  fc 35 3f a4
Sep 20 18:12:00 djpc pluto[9618]: |   eb 96 02 5b  1a 5f 6a f6  d2 c9 5a 
be  18 20 d0 91
Sep 20 18:12:00 djpc pluto[9618]: |   3b 20 11 1e  6b ea 59 a6
Sep 20 18:12:00 djpc pluto[9618]: "L2TP-PSK" #3: ASSERTION FAILED at 
kernel.c:2237: c->kind == CK_PERMANENT || c->kind == CK_INSTANCE
Sep 20 18:12:00 djpc pluto[9618]: "L2TP-PSK" #3: interface lo/lo ::1
Sep 20 18:12:00 djpc pluto[9618]: "L2TP-PSK" #3: interface lo/lo 127.0.0.1
Sep 20 18:12:00 djpc pluto[9618]: "L2TP-PSK" #3: interface eth0/eth0 
192.168.1.7
Sep 20 18:12:00 djpc pluto[9618]: "L2TP-PSK" #3: %myid = (none)
Sep 20 18:12:00 djpc pluto[9618]: "L2TP-PSK" #3: debug 
raw+crypt+parsing+emitting+control+lifecycle+klips+dns+oppo+controlmore+pfkey+nattraversal+x509
Sep 20 18:12:00 djpc pluto[9618]: "L2TP-PSK" #3:
Sep 20 18:12:00 djpc pluto[9618]: "L2TP-PSK" #3: algorithm ESP encrypt: 
id=2, name=ESP_DES, ivlen=8, keysizemin=64, keysizemax=64
Sep 20 18:12:00 djpc pluto[9618]: "L2TP-PSK" #3: algorithm ESP encrypt: 
id=3, name=ESP_3DES, ivlen=8, keysizemin=192, keysizemax=192
Sep 20 18:12:00 djpc pluto[9618]: "L2TP-PSK" #3: algorithm ESP encrypt: 
id=7, name=ESP_BLOWFISH, ivlen=8, keysizemin=40, keysizemax=448
Sep 20 18:12:00 djpc pluto[9618]: "L2TP-PSK" #3: algorithm ESP encrypt: 
id=11, name=ESP_NULL, ivlen=0, keysizemin=0, keysizemax=0
Sep 20 18:12:00 djpc pluto[9618]: "L2TP-PSK" #3: algorithm ESP encrypt: 
id=12, name=ESP_AES, ivlen=8, keysizemin=128, keysizemax=256
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm ESP encrypt: 
id=252, name=ESP_SERPENT, ivlen=8, keysizemin=128, keysizemax=256
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm ESP encrypt: 
id=253, name=ESP_TWOFISH, ivlen=8, keysizemin=128, keysizemax=256
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm ESP auth 
attr: id=1, name=AUTH_ALGORITHM_HMAC_MD5, keysizemin=128, keysizemax=128
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm ESP auth 
attr: id=2, name=AUTH_ALGORITHM_HMAC_SHA1, keysizemin=160, keysizemax=160
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm ESP auth 
attr: id=5, name=AUTH_ALGORITHM_HMAC_SHA2_256, keysizemin=256, 
keysizemax=256
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm ESP auth 
attr: id=251, name=(null), keysizemin=0, keysizemax=0
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3:
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm IKE encrypt: 
id=5, name=OAKLEY_3DES_CBC, blocksize=8, keydeflen=192
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm IKE encrypt: 
id=7, name=OAKLEY_AES_CBC, blocksize=16, keydeflen=128
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm IKE hash: 
id=1, name=OAKLEY_MD5, hashsize=16
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm IKE hash: 
id=2, name=OAKLEY_SHA1, hashsize=20
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm IKE dh group: 
id=2, name=OAKLEY_GROUP_MODP1024, bits=1024
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm IKE dh group: 
id=5, name=OAKLEY_GROUP_MODP1536, bits=1536
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm IKE dh group: 
id=14, name=OAKLEY_GROUP_MODP2048, bits=2048
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm IKE dh group: 
id=15, name=OAKLEY_GROUP_MODP3072, bits=3072
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm IKE dh group: 
id=16, name=OAKLEY_GROUP_MODP4096, bits=4096
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm IKE dh group: 
id=17, name=OAKLEY_GROUP_MODP6144, bits=6144
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: algorithm IKE dh group: 
id=18, name=OAKLEY_GROUP_MODP8192, bits=8192
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3:
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: stats db_ops.c: 
{curr_cnt, total_cnt, maxsz} :context={0,0,0} trans={0,0,0} attrs={0,0,0}
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3:
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: "L2TP-PSK": 
192.168.1.7:17/1701...192.168.1.250:17/1701; unrouted; eroute owner: #0
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: "L2TP-PSK": 
srcip=unset; dstip=unset; srcup=ipsec _updown; dstup=ipsec _updown;
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: "L2TP-PSK":   ike_life: 
3600s; ipsec_life: 28800s; rekey_margin: 540s; rekey_fuzz: 100%; 
keyingtries: 3
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: "L2TP-PSK":   policy: 
PSK+ENCRYPT+TUNNEL+DONTREKEY; prio: 32,32; interface: eth0;
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: "L2TP-PSK":   newest 
ISAKMP SA: #1; newest IPsec SA: #0;
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: "L2TP-PSK":   IKE 
algorithm newest: 3DES_CBC_192-SHA1-MODP2048
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3:
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: #3: "L2TP-PSK":500 
STATE_QUICK_R0 (expecting QI1); EVENT_CRYPTO_FAILED in 296s; nodpd
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: #1: "L2TP-PSK":500 
STATE_MAIN_R3 (sent MR3, ISAKMP SA established); EVENT_SA_EXPIRE in 
28792s; newest ISAKMP; nodpd
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3: #2: "L2TP-PSK":500 
STATE_MAIN_R1 (sent MR1, expecting MI2); EVENT_RETRANSMIT in -2s; nodpd
Sep 20 18:12:01 djpc pluto[9618]: "L2TP-PSK" #3:
Sep 20 18:12:12 djpc ipsec__plutorun: Restarting Pluto subsystem...
Sep 20 18:12:12 djpc pluto[9846]: Starting Pluto (Openswan Version 2.4.4 
X.509-1.5.4 PLUTO_SENDS_VENDORID PLUTO_USES_KEYRR; Vendor ID OEz}FFFfgr_e)
Sep 20 18:12:12 djpc pluto[9846]: Setting NAT-Traversal port-4500 
floating to off
Sep 20 18:12:12 djpc pluto[9846]:    port floating activation criteria 
nat_t=0/port_fload=1
Sep 20 18:12:12 djpc pluto[9846]:   including NAT-Traversal patch 
(Version 0.6c) [disabled]
Sep 20 18:12:12 djpc pluto[9846]: | opening /dev/urandom
Sep 20 18:12:12 djpc pluto[9846]: | inserting event EVENT_REINIT_SECRET, 
timeout in 3600 seconds
Sep 20 18:12:12 djpc pluto[9846]: | inserting event 
EVENT_PENDING_PHASE2, timeout in 120 seconds
Sep 20 18:12:12 djpc pluto[9846]: ike_alg_register_enc(): Activating 
OAKLEY_AES_CBC: Ok (ret=0)
Sep 20 18:12:12 djpc pluto[9846]: starting up 1 cryptographic helpers
Sep 20 18:12:12 djpc pluto[9852]: | opening /dev/urandom
Sep 20 18:12:12 djpc pluto[9846]: started helper pid=9852 (fd:6)
Sep 20 18:12:12 djpc pluto[9846]: | process 9846 listening for PF_KEY_V2 
on file descriptor 7
Sep 20 18:12:12 djpc pluto[9852]: ! helper 0 waiting on fd: 7
Sep 20 18:12:12 djpc pluto[9846]: Using Linux 2.6 IPsec interface code 
on 2.6.15-27-k7
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_hdr_build:
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_hdr_build: 
on_entry &pfkey_ext=0p0xbf9f40b0 pfkey_ext=0p0xbf9f50d0 *pfkey_ext=0p(nil).
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_hdr_build: 
on_exit &pfkey_ext=0p0xbf9f40b0 pfkey_ext=0p0xbf9f50d0 
*pfkey_ext=0p0x80fadc0.
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_build: 
pfkey_msg=0p0x80fadd8 allocated 16 bytes, &(extensions[0])=0p0xbf9f50d0
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_build: 
extensions permitted=00000001, seen=00000001, required=00000001.
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_parse: 
parsing message ver=2, type=7(register), errno=0, satype=2(AH), len=2, 
res=0, seq=1, pid=9846.
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_parse: 
remain=0
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_parse: 
extensions permitted=00000001, required=00000001.
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_parse: 
extensions permitted=00000001, seen=00000001, required=00000001.
Sep 20 18:12:12 djpc pluto[9846]: | finish_pfkey_msg: SADB_REGISTER 
message 1 for AH
Sep 20 18:12:12 djpc pluto[9846]: |   02 07 00 02  02 00 00 00  01 00 00 
00  76 26 00 00
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_get: SADB_REGISTER message 1
Sep 20 18:12:12 djpc pluto[9846]: | AH registered with kernel.
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_hdr_build:
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_hdr_build: 
on_entry &pfkey_ext=0p0xbf9f40b0 pfkey_ext=0p0xbf9f50d0 *pfkey_ext=0p(nil).
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_hdr_build: 
on_exit &pfkey_ext=0p0xbf9f40b0 pfkey_ext=0p0xbf9f50d0 
*pfkey_ext=0p0x80fadc0.
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_build: 
pfkey_msg=0p0x80fadd8 allocated 16 bytes, &(extensions[0])=0p0xbf9f50d0
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_build: 
extensions permitted=00000001, seen=00000001, required=00000001.
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_parse: 
parsing message ver=2, type=7(register), errno=0, satype=3(ESP), len=2, 
res=0, seq=2, pid=9846.
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_parse: 
remain=0
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_parse: 
extensions permitted=00000001, required=00000001.
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_parse: 
extensions permitted=00000001, seen=00000001, required=00000001.
Sep 20 18:12:12 djpc pluto[9846]: | finish_pfkey_msg: SADB_REGISTER 
message 2 for ESP
Sep 20 18:12:12 djpc pluto[9846]: |   02 07 00 03  02 00 00 00  02 00 00 
00  76 26 00 00
Sep 20 18:12:12 djpc pluto[9846]: | pfkey_get: SADB_REGISTER message 2
Sep 20 18:12:13 djpc pluto[9846]: | alg_init():memset(0x80f9000, 0, 
2016) memset(0x80f97e0, 0, 2048)
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_register_pfkey(): 
SADB_SATYPE_ESP: sadb_msg_len=15 sadb_supported_len=40
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_add():satype=3, 
exttype=14, alg_id=251
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_register_pfkey(): 
SADB_SATYPE_ESP: alg[0], exttype=14, satype=3, alg_id=251, alg_ivlen=0, 
alg_minbits=0, alg_maxbits=0, res=0, ret=1
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_add():satype=3, 
exttype=14, alg_id=2
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_register_pfkey(): 
SADB_SATYPE_ESP: alg[1], exttype=14, satype=3, alg_id=2, alg_ivlen=0, 
alg_minbits=128, alg_maxbits=128, res=0, ret=1
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_add():satype=3, 
exttype=14, alg_id=3
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_register_pfkey(): 
SADB_SATYPE_ESP: alg[2], exttype=14, satype=3, alg_id=3, alg_ivlen=0, 
alg_minbits=160, alg_maxbits=160, res=0, ret=1
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_add():satype=3, 
exttype=14, alg_id=5
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_register_pfkey(): 
SADB_SATYPE_ESP: alg[3], exttype=14, satype=3, alg_id=5, alg_ivlen=0, 
alg_minbits=256, alg_maxbits=256, res=0, ret=1
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_register_pfkey(): 
SADB_SATYPE_ESP: sadb_msg_len=15 sadb_supported_len=64
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_add():satype=3, 
exttype=15, alg_id=11
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_register_pfkey(): 
SADB_SATYPE_ESP: alg[4], exttype=15, satype=3, alg_id=11, alg_ivlen=0, 
alg_minbits=0, alg_maxbits=0, res=0, ret=1
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_add():satype=3, 
exttype=15, alg_id=2
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_register_pfkey(): 
SADB_SATYPE_ESP: alg[5], exttype=15, satype=3, alg_id=2, alg_ivlen=8, 
alg_minbits=64, alg_maxbits=64, res=0, ret=1
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_add():satype=3, 
exttype=15, alg_id=3
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_register_pfkey(): 
SADB_SATYPE_ESP: alg[6], exttype=15, satype=3, alg_id=3, alg_ivlen=8, 
alg_minbits=192, alg_maxbits=192, res=0, ret=1
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_add():satype=3, 
exttype=15, alg_id=7
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_register_pfkey(): 
SADB_SATYPE_ESP: alg[7], exttype=15, satype=3, alg_id=7, alg_ivlen=8, 
alg_minbits=40, alg_maxbits=448, res=0, ret=1
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_add():satype=3, 
exttype=15, alg_id=12
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_register_pfkey(): 
SADB_SATYPE_ESP: alg[8], exttype=15, satype=3, alg_id=12, alg_ivlen=8, 
alg_minbits=128, alg_maxbits=256, res=0, ret=1
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_add():satype=3, 
exttype=15, alg_id=252
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_register_pfkey(): 
SADB_SATYPE_ESP: alg[9], exttype=15, satype=3, alg_id=252, alg_ivlen=8, 
alg_minbits=128, alg_maxbits=256, res=0, ret=1
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_add():satype=3, 
exttype=15, alg_id=253
Sep 20 18:12:13 djpc pluto[9846]: | kernel_alg_register_pfkey(): 
SADB_SATYPE_ESP: alg[10], exttype=15, satype=3, alg_id=253, alg_ivlen=8, 
alg_minbits=128, alg_maxbits=256, res=0, ret=1
Sep 20 18:12:13 djpc pluto[9846]: | ESP registered with kernel.
Sep 20 18:12:13 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_hdr_build:
Sep 20 18:12:13 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_hdr_build: 
on_entry &pfkey_ext=0p0xbf9f40b0 pfkey_ext=0p0xbf9f50d0 *pfkey_ext=0p(nil).
Sep 20 18:12:13 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_hdr_build: 
on_exit &pfkey_ext=0p0xbf9f40b0 pfkey_ext=0p0xbf9f50d0 
*pfkey_ext=0p0x80fadc0.
Sep 20 18:12:13 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_build: 
pfkey_msg=0p0x80fadd8 allocated 16 bytes, &(extensions[0])=0p0xbf9f50d0
Sep 20 18:12:13 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_build: 
extensions permitted=00000001, seen=00000001, required=00000001.
Sep 20 18:12:13 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_parse: 
parsing message ver=2, type=7(register), errno=0, satype=9(IPIP), len=2, 
res=0, seq=3, pid=9846.
Sep 20 18:12:13 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_parse: 
remain=0
Sep 20 18:12:13 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_parse: 
extensions permitted=00000001, required=00000001.
Sep 20 18:12:13 djpc pluto[9846]: | pfkey_lib_debug:pfkey_msg_parse: 
extensions permitted=00000001, seen=00000001, required=00000001.
Sep 20 18:12:13 djpc pluto[9846]: | finish_pfkey_msg: SADB_REGISTER 
message 3 for IPCOMP
Sep 20 18:12:13 djpc pluto[9846]: |   02 07 00 09  02 00 00 00  03 00 00 
00  76 26 00 00
Sep 20 18:12:13 djpc pluto[9846]: | pfkey_get: SADB_REGISTER message 3
Sep 20 18:12:13 djpc pluto[9846]: | IPCOMP registered with kernel.
Sep 20 18:12:13 djpc pluto[9846]: Changing to directory 
'/etc/ipsec.d/cacerts'
Sep 20 18:12:13 djpc pluto[9846]: Changing to directory 
'/etc/ipsec.d/aacerts'
Sep 20 18:12:13 djpc pluto[9846]: Changing to directory 
'/etc/ipsec.d/ocspcerts'
Sep 20 18:12:13 djpc pluto[9846]: Changing to directory '/etc/ipsec.d/crls'
Sep 20 18:12:13 djpc pluto[9846]:   Warning: empty directory
Sep 20 18:12:13 djpc pluto[9846]: | inserting event EVENT_LOG_DAILY, 
timeout in 20867 seconds
Sep 20 18:12:13 djpc pluto[9846]: | next event EVENT_PENDING_PHASE2 in 
119 seconds
Sep 20 18:12:13 djpc pluto[9846]: |
Sep 20 18:12:13 djpc pluto[9846]: | *received whack message
Sep 20 18:12:13 djpc pluto[9846]: | Added new connection L2TP-PSK with 
policy PSK+ENCRYPT+TUNNEL+DONTREKEY
Sep 20 18:12:13 djpc pluto[9846]: | counting wild cards for (none) is 15
Sep 20 18:12:13 djpc pluto[9846]: | counting wild cards for (none) is 15
Sep 20 18:12:13 djpc pluto[9846]: | based upon policy, the connection is 
a template.
Sep 20 18:12:13 djpc pluto[9846]: added connection description "L2TP-PSK"
Sep 20 18:12:13 djpc pluto[9846]: | 
192.168.1.7:17/1701...192.168.1.250:17/%any
Sep 20 18:12:13 djpc pluto[9846]: | ike_life: 3600s; ipsec_life: 28800s; 
rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 3; policy: 
PSK+ENCRYPT+TUNNEL+DONTREKEY
Sep 20 18:12:13 djpc pluto[9846]: | next event EVENT_PENDING_PHASE2 in 
119 seconds
Sep 20 18:12:13 djpc pluto[9846]: |
Sep 20 18:12:13 djpc pluto[9846]: | *received whack message
Sep 20 18:12:13 djpc pluto[9846]: listening for IKE messages
Sep 20 18:12:13 djpc pluto[9846]: | found lo with address 127.0.0.1
Sep 20 18:12:13 djpc pluto[9846]: | found eth0 with address 192.168.1.7
Sep 20 18:12:13 djpc pluto[9846]: adding interface eth0/eth0 192.168.1.7:500
Sep 20 18:12:13 djpc pluto[9846]: adding interface lo/lo 127.0.0.1:500
Sep 20 18:12:13 djpc pluto[9846]: | found lo with address 
0000:0000:0000:0000:0000:0000:0000:0001
Sep 20 18:12:13 djpc pluto[9846]: adding interface lo/lo ::1:500
Sep 20 18:12:13 djpc pluto[9846]: | connect_to_host_pair: 
192.168.1.7:500 192.168.1.250:500 -> hp:none
Sep 20 18:12:13 djpc pluto[9846]: loading secrets from "/etc/ipsec.secrets"
Sep 20 18:12:13 djpc pluto[9846]:   loaded private key file 
'/etc/ipsec.d/private/djpcKey.pem' (1679 bytes)
Sep 20 18:12:13 djpc pluto[9846]: |   file content is not binary ASN.1
Sep 20 18:12:13 djpc pluto[9846]: |   -----BEGIN RSA PRIVATE KEY-----
Sep 20 18:12:13 djpc pluto[9846]: |   -----END RSA PRIVATE KEY-----
Sep 20 18:12:13 djpc pluto[9846]: |   file coded in PEM format
Sep 20 18:12:13 djpc pluto[9846]: | L0 - RSAPrivateKey:
Sep 20 18:12:13 djpc pluto[9846]: | L1 - version:
Sep 20 18:12:13 djpc pluto[9846]: | L1 - modulus:
Sep 20 18:12:13 djpc pluto[9846]: | L1 - publicExponent:
Sep 20 18:12:13 djpc pluto[9846]: | L1 - privateExponent:
Sep 20 18:12:13 djpc pluto[9846]: | L1 - prime1:
Sep 20 18:12:13 djpc pluto[9846]: | L1 - prime2:
Sep 20 18:12:13 djpc pluto[9846]: | L1 - exponent1:
Sep 20 18:12:13 djpc pluto[9846]: | L1 - exponent2:
Sep 20 18:12:13 djpc pluto[9846]: | L1 - coefficient:
Sep 20 18:12:14 djpc pluto[9846]: | loaded private key for keyid: 
PPK_RSA:AwEAAcC/9
Sep 20 18:12:14 djpc pluto[9846]: | next event EVENT_PENDING_PHASE2 in 
119 seconds
Sep 20 18:12:24 djpc pluto[9846]: |
Sep 20 18:12:24 djpc pluto[9846]: | *received 1300 bytes from 
192.168.1.250:500 on eth0 (port=500)
Sep 20 18:12:24 djpc pluto[9846]: |   a3 72 2c 3e  72 f6 22 46  8d 38 1b 
33  f4 c5 e0 f4
Sep 20 18:12:25 djpc pluto[9846]: |   08 10 20 01  6c aa 7a e4  00 00 05 
14  d7 c7 ff cc
Sep 20 18:12:25 djpc pluto[9846]: |   aa 11 b0 fd  cb b5 35 d8  28 12 c4 
6f  5e 7b b2 4e
Sep 20 18:12:25 djpc pluto[9846]: |   31 32 06 92  89 8a 2f 13  ee 3a 21 
cb  d6 85 e2 b6
Sep 20 18:12:25 djpc pluto[9846]: |   22 7c 2d 03  c0 b5 8a c8  f3 11 ef 
3f  bf fe 4a 7a
Sep 20 18:12:25 djpc pluto[9846]: |   58 5b b4 3f  3b 12 bb 16  a1 21 51 
c3  cc a8 83 af
Sep 20 18:12:25 djpc pluto[9846]: |   8c a8 2f 60  fd 27 8c f1  e9 e7 9d 
24  d2 84 10 a6
Sep 20 18:12:25 djpc pluto[9846]: |   c4 90 70 e2  46 74 10 cd  7c 64 48 
7d  7f e6 89 f5
Sep 20 18:12:25 djpc pluto[9846]: |   54 c8 f8 99  e4 58 bb 46  04 cb 61 
de  2c 40 eb 29
Sep 20 18:12:25 djpc pluto[9846]: |   5d 08 0a 3b  dd 9e 3a de  dd 9a 39 
28  04 d5 d9 3a
Sep 20 18:12:25 djpc pluto[9846]: |   0d fe 5a 77  ac 3d 2e ce  24 3c 65 
66  c2 9c d6 ac
Sep 20 18:12:25 djpc pluto[9846]: |   e9 4a ef 3a  d4 5d c6 0d  9f 7f 63 
cc  70 05 8d c6
Sep 20 18:12:25 djpc pluto[9846]: |   b5 e5 03 2d  2b 4a d8 08  77 2b 53 
e5  9b c4 0d 30
Sep 20 18:12:25 djpc pluto[9846]: |   df c4 a6 89  ff 9c 6b ce  63 6f 9d 
20  52 f2 a2 a5
Sep 20 18:12:25 djpc pluto[9846]: |   a1 39 05 f1  96 9c 2e 42  83 83 ad 
f9  2e 05 91 13
Sep 20 18:12:25 djpc pluto[9846]: |   64 2b 21 9e  3b a2 57 eb  06 ba 5d 
29  50 11 ef 8c
Sep 20 18:12:25 djpc pluto[9846]: |   52 18 7d a8  f4 68 45 91  bc c0 d5 
ab  1e 8f 75 55
Sep 20 18:12:25 djpc pluto[9846]: |   8b 35 2b 07  00 29 ce 0d  3d f7 2d 
6b  ac 1a 03 70
Sep 20 18:12:25 djpc pluto[9846]: |   58 5b 54 99  65 0a ca d0  fc f0 c4 
b5  ca 63 bc 84
Sep 20 18:12:25 djpc pluto[9846]: |   5b fd 1e 1f  3f a1 a3 8d  e7 d4 39 
87  56 f6 40 17
Sep 20 18:12:25 djpc pluto[9846]: |   d0 53 c7 6e  15 e0 a3 e8  16 62 c2 
fd  9f 25 c9 85
Sep 20 18:12:25 djpc pluto[9846]: |   15 9d bb 31  6b 59 51 58  99 b3 2b 
86  de e6 6e dc
Sep 20 18:12:25 djpc pluto[9846]: |   3b 65 76 c3  a6 2d c5 fc  8c c9 e3 
69  2b c5 89 97
Sep 20 18:12:25 djpc pluto[9846]: |   0f 0a 8d 3d  c0 b4 0a aa  03 e9 33 
78  74 38 78 84
Sep 20 18:12:25 djpc pluto[9846]: |   79 dc a4 e8  47 dd 1c 69  bf b7 53 
51  50 11 1a 04
Sep 20 18:12:25 djpc pluto[9846]: |   85 18 bb f4  21 e8 96 00  af 99 34 
81  41 5e 77 62
Sep 20 18:12:25 djpc pluto[9846]: |   13 61 96 23  8d bf ff e9  8e f4 33 
e7  41 d7 0d ab
Sep 20 18:12:25 djpc pluto[9846]: |   a8 e6 89 e9  96 d9 7e 6b  6f 2b 55 
42  13 83 b1 40
Sep 20 18:12:25 djpc pluto[9846]: |   e7 c3 e5 ce  cf ec d3 3c  ee 60 38 
df  ab b2 66 a5
Sep 20 18:12:25 djpc pluto[9846]: |   56 0c e3 6b  3e 5a 87 c4  15 3b e4 
0a  ae 99 8f 5f
Sep 20 18:12:25 djpc pluto[9846]: |   67 19 3f ac  bb 98 03 74  38 3d 05 
f5  b5 18 2b 4d
Sep 20 18:12:25 djpc pluto[9846]: |   b1 27 c4 a8  a9 c9 76 de  04 80 61 
fb  c5 21 47 ae
Sep 20 18:12:25 djpc pluto[9846]: |   92 87 0f 20  49 f1 26 4d  1e 2b 8f 
5a  78 fc 12 8a
Sep 20 18:12:25 djpc pluto[9846]: |   6b 55 02 ce  c5 b0 64 0c  70 8a c1 
b0  b1 44 60 d7
Sep 20 18:12:25 djpc pluto[9846]: |   2d 8a 61 c0  24 15 cd 04  c1 bf 18 
eb  81 ab 01 8a
Sep 20 18:12:25 djpc pluto[9846]: |   82 3f 30 e0  36 07 4d 2a  5c ff 07 
51  fe ba 71 d3
Sep 20 18:12:25 djpc pluto[9846]: |   c9 f8 10 1e  d9 c7 71 fc  c8 6b da 
74  77 02 76 51
Sep 20 18:12:25 djpc pluto[9846]: |   7a 1d 2e 54  95 eb 6e f1  b6 d5 4c 
13  01 d5 a0 84
Sep 20 18:12:25 djpc pluto[9846]: |   19 3a 83 64  b4 aa b7 c2  a3 4b 80 
cd  19 3d a1 a9
Sep 20 18:12:25 djpc pluto[9846]: |   7c e9 21 24  55 4b 8a 34  66 bb 08 
ff  32 33 e1 68
Sep 20 18:12:25 djpc pluto[9846]: |   0f 42 5a 3a  11 1a c6 cf  9e 8c bc 
ec  ed e9 9f 49
Sep 20 18:12:25 djpc pluto[9846]: |   f4 b1 27 9c  75 0f 5d 41  26 1e 3c 
78  9e 09 c1 93
Sep 20 18:12:25 djpc pluto[9846]: |   a4 71 d1 b3  0e 33 6e 49  86 4d e0 
a3  ea cb ff b4
Sep 20 18:12:25 djpc pluto[9846]: |   04 c0 1c 51  44 3c f4 53  d8 f2 13 
5f  90 1f ea 61
Sep 20 18:12:25 djpc pluto[9846]: |   6e d5 d4 14  06 6c e8 ea  64 3b 33 
4e  c9 8a e6 4d
Sep 20 18:12:25 djpc pluto[9846]: |   ce 37 f7 84  18 01 79 40  d3 46 7b 
fb  cc d3 c9 3c
Sep 20 18:12:25 djpc pluto[9846]: |   83 16 04 cc  a6 fb d9 8c  08 18 38 
12  55 60 3b 3f
Sep 20 18:12:25 djpc pluto[9846]: |   74 1a 46 39  34 11 5d 4b  5f 42 94 
d3  af 41 61 26
Sep 20 18:12:25 djpc pluto[9846]: |   93 e2 6d da  14 68 70 0f  78 d6 32 
c7  51 dd c9 75
Sep 20 18:12:25 djpc pluto[9846]: |   94 20 43 82  f5 3e 28 f1  b8 cf b1 
0e  e8 e7 4d c3
Sep 20 18:12:25 djpc pluto[9846]: |   08 15 a8 39  98 4f 5d 68  92 e5 22 
1c  08 84 66 19
Sep 20 18:12:25 djpc pluto[9846]: |   4c 9f a2 cc  25 a3 cf ad  56 31 1b 
0a  24 fc 61 ff
Sep 20 18:12:25 djpc pluto[9846]: |   a9 f5 b2 36  ee bf 74 c5  88 2e 2b 
9c  d0 a6 73 b5
Sep 20 18:12:25 djpc pluto[9846]: |   b1 2a 75 46  32 20 b4 c2  39 2f 78 
6b  27 84 dc 74
Sep 20 18:12:25 djpc pluto[9846]: |   8e 0a a5 64  5d d6 96 9f  4a b4 75 
37  c0 6e 06 0e
Sep 20 18:12:25 djpc pluto[9846]: |   ac 8c 8a d2  e2 97 84 ed  d6 e2 19 
8e  0d 9d 68 0e
Sep 20 18:12:25 djpc pluto[9846]: |   03 c0 dc 2e  c8 20 64 73  83 77 41 
44  37 b4 3c 63
Sep 20 18:12:25 djpc pluto[9846]: |   5e d3 9b b0  14 d6 35 1c  af dd 3f 
a4  7c 38 3b 78
Sep 20 18:12:25 djpc pluto[9846]: |   77 2c ad c1  5a 42 ed ea  4b ee 4f 
5a  aa 1d 5c ae
Sep 20 18:12:25 djpc pluto[9846]: |   96 09 d2 91  66 38 00 26  cc 93 b2 
40  ca 75 f3 dc
Sep 20 18:12:25 djpc pluto[9846]: |   b0 d1 68 08  9f 96 fe 6b  87 91 45 
29  18 1e c7 82
Sep 20 18:12:25 djpc pluto[9846]: |   2b ad a0 bf  de 92 9d bb  d5 6b 15 
f6  01 5a d3 21
Sep 20 18:12:25 djpc pluto[9846]: |   b0 2b 6c f7  00 dc 52 ce  ea 69 87 
ff  37 dc aa c3
Sep 20 18:12:25 djpc pluto[9846]: |   10 cc d4 66  6f 5b 0b c2  7c c2 0f 
e2  e9 72 9e 50
Sep 20 18:12:25 djpc pluto[9846]: |   18 c9 f0 8f  af a2 bb 59  e1 da 32 
a4  ad b0 f9 06
Sep 20 18:12:25 djpc pluto[9846]: |   ce 85 36 ba  4b 51 c8 da  bc 20 2a 
32  a3 bb 86 de
Sep 20 18:12:25 djpc pluto[9846]: |   18 cd c9 79  5f a5 d1 c2  d7 09 56 
84  84 fc 1f 21
Sep 20 18:12:25 djpc pluto[9846]: |   d1 14 e6 1d  a5 cb bf 86  1d b1 c8 
53  44 05 e9 71
Sep 20 18:12:25 djpc pluto[9846]: |   57 3c ab bf  5b c7 1a 73  16 46 17 
76  13 56 54 85
Sep 20 18:12:25 djpc pluto[9846]: |   3c 43 7b 9c  f9 53 b6 09  85 ba d5 
71  6c 97 5c 89
Sep 20 18:12:25 djpc pluto[9846]: |   d2 a4 b9 15  8f 08 ac 75  8d 57 0b 
c8  b3 89 c6 29
Sep 20 18:12:25 djpc pluto[9846]: |   64 52 d6 9a  42 3d 0c c3  5a 58 05 
49  a1 a1 e6 3e
Sep 20 18:12:25 djpc pluto[9846]: |   11 8d eb fe  36 50 b1 82  19 1e 05 
d1  2c d5 05 5b
Sep 20 18:12:25 djpc pluto[9846]: |   c7 7b 62 b4  68 1b aa 97  c1 e1 61 
7e  8d cd 7a 45
Sep 20 18:12:25 djpc pluto[9846]: |   cc 9e 63 33  8e 9c 13 0b  8c e4 9b 
46  5b a3 31 70
Sep 20 18:12:25 djpc pluto[9846]: |   d3 0b 11 c0  7d b4 50 8a  1c d4 4f 
58  84 bb f4 ea
Sep 20 18:12:25 djpc pluto[9846]: |   bf 0d 5f 34  4c 5a 7a 6d  d0 f8 d6 
45  3d 50 39 0a
Sep 20 18:12:25 djpc pluto[9846]: |   af a3 e4 d3  df 85 c7 da  c2 e0 b5 
e0  a4 13 c0 1e
Sep 20 18:12:25 djpc pluto[9846]: |   25 1d 5c f4  bb 39 85 2e  a3 b9 4a 
9e  b6 f1 8b 5e
Sep 20 18:12:25 djpc pluto[9846]: |   f0 ef da aa  2f ff a6 8c  19 e0 08 
0d  19 e5 72 ff
Sep 20 18:12:25 djpc pluto[9846]: |   28 47 a2 54  cc df c2 4d  2e 4c ea 
ea  f7 29 1f 9c
Sep 20 18:12:25 djpc pluto[9846]: |   0c dd a8 02
Sep 20 18:12:25 djpc pluto[9846]: | **parse ISAKMP Message:
Sep 20 18:12:25 djpc pluto[9846]: |    initiator cookie:
Sep 20 18:12:25 djpc pluto[9846]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:12:25 djpc pluto[9846]: |    responder cookie:
Sep 20 18:12:25 djpc pluto[9846]: |   8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:12:25 djpc pluto[9846]: |    next payload type: ISAKMP_NEXT_HASH
Sep 20 18:12:25 djpc pluto[9846]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:12:25 djpc pluto[9846]: |    exchange type: ISAKMP_XCHG_QUICK
Sep 20 18:12:25 djpc pluto[9846]: |    flags: ISAKMP_FLAG_ENCRYPTION
Sep 20 18:12:25 djpc pluto[9846]: |    message ID:  6c aa 7a e4
Sep 20 18:12:25 djpc pluto[9846]: |    length: 1300
Sep 20 18:12:25 djpc pluto[9846]: |  processing packet with exchange 
type=ISAKMP_XCHG_QUICK (32)
Sep 20 18:12:25 djpc pluto[9846]: | ICOOKIE:  a3 72 2c 3e  72 f6 22 46
Sep 20 18:12:25 djpc pluto[9846]: | RCOOKIE:  8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:12:25 djpc pluto[9846]: | peer:  c0 a8 01 fa
Sep 20 18:12:25 djpc pluto[9846]: | state hash entry 0
Sep 20 18:12:26 djpc pluto[9846]: | state object not found
Sep 20 18:12:26 djpc pluto[9846]: | ICOOKIE:  a3 72 2c 3e  72 f6 22 46
Sep 20 18:12:26 djpc pluto[9846]: | RCOOKIE:  8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:12:26 djpc pluto[9846]: | peer:  c0 a8 01 fa
Sep 20 18:12:26 djpc pluto[9846]: | state hash entry 0
Sep 20 18:12:26 djpc pluto[9846]: | state object not found
Sep 20 18:12:26 djpc pluto[9846]: packet from 192.168.1.250:500: Quick 
Mode message is for a non-existent (expired?) ISAKMP SA
Sep 20 18:12:26 djpc pluto[9846]: | next event EVENT_PENDING_PHASE2 in 
107 seconds
Sep 20 18:12:57 djpc pluto[9846]: |
Sep 20 18:12:57 djpc pluto[9846]: | *received 84 bytes from 
192.168.1.250:500 on eth0 (port=500)
Sep 20 18:12:57 djpc pluto[9846]: |   a3 72 2c 3e  72 f6 22 46  8d 38 1b 
33  f4 c5 e0 f4
Sep 20 18:12:57 djpc pluto[9846]: |   08 10 05 01  f5 67 9f fd  00 00 00 
54  f1 50 ab 18
Sep 20 18:12:57 djpc pluto[9846]: |   fd c1 fb 37  2b 98 2c 66  09 7b d8 
00  74 39 7e a4
Sep 20 18:12:57 djpc pluto[9846]: |   b6 c8 da 05  1f d6 59 c7  c4 12 da 
ca  bc db bb 7d
Sep 20 18:12:57 djpc pluto[9846]: |   f1 71 0d da  ee fb 8d 97  b4 90 90 
6a  bc 8b 3b 7e
Sep 20 18:12:57 djpc pluto[9846]: |   2e 9f 41 1b
Sep 20 18:12:57 djpc pluto[9846]: | **parse ISAKMP Message:
Sep 20 18:12:57 djpc pluto[9846]: |    initiator cookie:
Sep 20 18:12:57 djpc pluto[9846]: |   a3 72 2c 3e  72 f6 22 46
Sep 20 18:12:57 djpc pluto[9846]: |    responder cookie:
Sep 20 18:12:57 djpc pluto[9846]: |   8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:12:57 djpc pluto[9846]: |    next payload type: ISAKMP_NEXT_HASH
Sep 20 18:12:57 djpc pluto[9846]: |    ISAKMP version: ISAKMP Version 1.0
Sep 20 18:12:57 djpc pluto[9846]: |    exchange type: ISAKMP_XCHG_INFO
Sep 20 18:12:57 djpc pluto[9846]: |    flags: ISAKMP_FLAG_ENCRYPTION
Sep 20 18:12:57 djpc pluto[9846]: |    message ID:  f5 67 9f fd
Sep 20 18:12:57 djpc pluto[9846]: |    length: 84
Sep 20 18:12:57 djpc pluto[9846]: |  processing packet with exchange 
type=ISAKMP_XCHG_INFO (5)
Sep 20 18:12:57 djpc pluto[9846]: | ICOOKIE:  a3 72 2c 3e  72 f6 22 46
Sep 20 18:12:57 djpc pluto[9846]: | RCOOKIE:  8d 38 1b 33  f4 c5 e0 f4
Sep 20 18:12:57 djpc pluto[9846]: | peer:  c0 a8 01 fa
Sep 20 18:12:57 djpc pluto[9846]: | state hash entry 0
Sep 20 18:12:57 djpc pluto[9846]: | p15 state object not found
Sep 20 18:12:57 djpc pluto[9846]: packet from 192.168.1.250:500: 
Informational Exchange is for an unknown (expired?) SA
Sep 20 18:12:57 djpc pluto[9846]: | next event EVENT_PENDING_PHASE2 in 
75 seconds
Technical Details
Message-ID: <eerq1o$bh5$1@news.interia.pl>
Path: mbox-mo1.pugleaf.net!news-archive.icm.edu.pl!newsfeed.gazeta.pl!feed.news.interia.pl!not-for-mail

Show Full Headers
Complete Article Headers
Path: mbox-mo1.pugleaf.net!news-archive.icm.edu.pl!newsfeed.gazeta.pl!feed.news.interia.pl!not-for-mail
From: Daniel Jaworski <danielj_no_spam@poczta.fm>
Newsgroups: pl.comp.os.linux.sieci,pl.comp.networking
Subject: ipsec + l2tp vpn problem z uruchomieniem
Date: Wed, 20 Sep 2006 18:25:57 +0200
Organization: INTERIA.PL S.A.
Lines: 2934
Message-ID: <eerq1o$bh5$1@news.interia.pl>
NNTP-Posting-Host: ppp133250.ostnet.pl
Mime-Version: 1.0
X-Trace: news.interia.pl 1158769538 11813 62.133.133.250 (20 Sep 2006 16:25:38 GMT)
X-Complaints-To: usenet@news.interia.pl
NNTP-Posting-Date: Wed, 20 Sep 2006 16:25:38 +0000 (UTC)
User-Agent: Thunderbird 1.5.0.5 (X11/20060728)
X-Authenticated-User: danielj % poczta+fm
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit