[Openswan Users] Problem with ipsec connection

Wolfgang Rapp CrashOverload at gmx.de
Wed Jul 8 06:13:28 EDT 2009


Hi Paul,

here are the settings and logs are missed in my first mail.

I also tried the forceencaps option as you said. But no effect.


> STATE_QUICK_I2: sent QI2, IPsec SA established tunnel mode
{ESP/NAT=>0x5cf54fe1 <0x176959fd xfrm=3DES_0-HMAC_SHA1 NATOA=none NATD=none DPD=none}

It seem´s to be completed without NAT-T, but it´s not working.

Hope you got some hints for me.

PS: In the secure.txt is the log information from one try to connect. From the start of the ipsec service to the stop of the service.


On Mon, 6 Jul 2009, CrashOverload at gmx.de wrote:

> I got a problem to establish a IPSEC NAT-T connection from OpenSwan to 
> a
Nortel Gateway. From the Remote Admin I got encryption settings to set in my config. I´m Using OpenSwan 2.6.22 and CentOS 5.2
>
> But the connection is always pending in ike phase 2.

That does not seem to be true:

> ipsec.conf:
>
>        authby=secret
>        auto=add
>        ike=3des-sha1-modp1024
>        esp=3des-sha1
>        forceencaps=no
>        left=192.168.25.77
>        leftid=192.168.25.77
>        leftsubnet=192.168.25.77/32
>        pfs=yes
>        right=12.13.14.15
>        rightid=12.13.14.15
>        rightsubnet=192.168.66.77/32
>        type=tunnel
>
>
>
> Output from /var/log/messages:
> ipsec__plutorun: 003 NAT-Traversal: Trying new style NAT-T
> ipsec__plutorun: 003 NAT-Traversal: ESPINUDP(1) setup failed for new 
> style
NAT-T family IPv4 (errno=19)
> ipsec__plutorun: 003 NAT-Traversal: Trying old style NAT-T

That message needs some improvement, as it does not confirm that this is working or not. Did you patch the kernel with NAT-T patch when using KLIPS, or are you using NETKEY (you cut off lots of logs) ?
The new style nat-t cannot work on the 2.6.18 based rhel/centos kernel.

> Output from /var/log/secure:
> STATE_QUICK_I2: sent QI2, IPsec SA established tunnel mode
{ESP=>0x3ca25267 <0xf9dc8a26 xfrm=3DES_0 -HMAC_SHA1 NATOA=none NATD=none DPD=none}

This shows phase 2 completed, however, it appears to have done so without NAT. You should see something like

STATE_QUICK_I2: sent QI2, IPsec SA established tunnel mode
{ESP/NAT=>0xa5637a98 <0x1eeed27a xfrm=3DES_0 -HMAC_SHA1 NATOA=none NATD=1.2.3.4:4500 DPD=none}

Try forceencaps=yes ? And make sure you have nat_traversal=yes in your "config setup". (we should really change the default of that to yes if the option is not explicitely set to no)

Paul

-- 
GRATIS für alle GMX-Mitglieder: Die maxdome Movie-FLAT!
Jetzt freischalten unter http://portal.gmx.net/de/go/maxdome01
-------------- next part --------------
# basic configuration
config setup
        # Do not set debug options to debug configuration issues!
        # plutodebug / klipsdebug = "all", "none" or a combation from below:
        # "raw crypt parsing emitting control klips pfkey natt x509 dpd private"
        # eg:
        # plutodebug="control parsing"
        #
        # enable to get logs per-peer
        # plutoopts="--perpeerlog"
        #
        # Again: only enable plutodebug or klipsdebug when asked by a developer
        #
        # NAT-TRAVERSAL support, see README.NAT-Traversal
        nat_traversal=yes
        # exclude networks used on server side by adding %v4:!a.b.c.0/24
        virtual_private=%v4:10.0.0.0/8,%v4:192.168.0.0/16,%v4:172.16.0.0/12
        # OE is now off by default. Uncomment and change to on, to enable.
        oe=off
        # which IPsec stack to use. netkey,klips,mast,auto or none
        protostack=netkey

conn vpn-connection
        authby=secret
        auto=add
        ike=3des-sha1-modp1024
        esp=3des-sha1
        forceencaps=yes
        left=192.168.25.77
        leftid=192.168.25.77
        leftsubnet=192.168.25.77/32
        pfs=yes
        right=12.13.14.15
        rightid=12.13.14.15
        rightsubnet=192.168.66.77/32
        type=tunnel
-------------- next part --------------
Jul  7 09:39:52 localhost ipsec__plutorun: Starting Pluto subsystem...
Jul  7 09:39:52 localhost pluto[16393]: Starting Pluto (Openswan Version 2.6.22; Vendor ID OElj@]rTMBuM) pid:16393
Jul  7 09:39:52 localhost pluto[16393]: Setting NAT-Traversal port-4500 floating to on
Jul  7 09:39:52 localhost pluto[16393]:    port floating activation criteria nat_t=1/port_float=1
Jul  7 09:39:52 localhost pluto[16393]:    including NAT-Traversal patch (Version 0.6c)
Jul  7 09:39:52 localhost pluto[16393]: using /dev/urandom as source of random entropy
Jul  7 09:39:52 localhost pluto[16393]: ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC_SSH: Ok (ret=0)
Jul  7 09:39:52 localhost pluto[16393]: ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC: Ok (ret=0)
Jul  7 09:39:52 localhost pluto[16393]: ike_alg_register_enc(): Activating OAKLEY_SERPENT_CBC: Ok (ret=0)
Jul  7 09:39:52 localhost pluto[16393]: ike_alg_register_enc(): Activating OAKLEY_AES_CBC: Ok (ret=0)
Jul  7 09:39:52 localhost pluto[16393]: ike_alg_register_enc(): Activating OAKLEY_BLOWFISH_CBC: Ok (ret=0)
Jul  7 09:39:52 localhost pluto[16393]: ike_alg_register_hash(): Activating OAKLEY_SHA2_512: Ok (ret=0)
Jul  7 09:39:52 localhost pluto[16393]: ike_alg_register_hash(): Activating OAKLEY_SHA2_256: Ok (ret=0)
Jul  7 09:39:52 localhost pluto[16393]: starting up 1 cryptographic helpers
Jul  7 09:39:52 localhost pluto[16401]: using /dev/urandom as source of random entropy
Jul  7 09:39:52 localhost pluto[16393]: started helper pid=16401 (fd:7)
Jul  7 09:39:52 localhost pluto[16393]: Using Linux 2.6 IPsec interface code on 2.6.18-92.el5 (experimental code)
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_register_enc(): WARNING: enc alg=0 not found in constants.c:oakley_enc_names  
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_register_enc(): Activating <NULL>: Ok (ret=0)
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_register_enc(): WARNING: enc alg=0 not found in constants.c:oakley_enc_names  
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_add(): ERROR: Algorithm already exists
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_register_enc(): Activating <NULL>: FAILED (ret=-17)
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_register_enc(): WARNING: enc alg=0 not found in constants.c:oakley_enc_names  
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_add(): ERROR: Algorithm already exists
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_register_enc(): Activating <NULL>: FAILED (ret=-17)
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_register_enc(): WARNING: enc alg=0 not found in constants.c:oakley_enc_names  
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_add(): ERROR: Algorithm already exists
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_register_enc(): Activating <NULL>: FAILED (ret=-17)
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_register_enc(): WARNING: enc alg=0 not found in constants.c:oakley_enc_names  
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_add(): ERROR: Algorithm already exists
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_register_enc(): Activating <NULL>: FAILED (ret=-17)
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_register_enc(): WARNING: enc alg=0 not found in constants.c:oakley_enc_names  
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_add(): ERROR: Algorithm already exists
Jul  7 09:39:53 localhost pluto[16393]: ike_alg_register_enc(): Activating <NULL>: FAILED (ret=-17)
Jul  7 09:39:53 localhost pluto[16393]: Changed path to directory '/etc/ipsec.d/cacerts'
Jul  7 09:39:53 localhost pluto[16393]: Changed path to directory '/etc/ipsec.d/aacerts'
Jul  7 09:39:53 localhost pluto[16393]: Changed path to directory '/etc/ipsec.d/ocspcerts'
Jul  7 09:39:53 localhost pluto[16393]: Changing to directory '/etc/ipsec.d/crls'
Jul  7 09:39:53 localhost pluto[16393]:   Warning: empty directory
Jul  7 09:39:53 localhost pluto[16393]: added connection description "vpn-connection"
Jul  7 09:39:53 localhost pluto[16393]: listening for IKE messages
Jul  7 09:39:53 localhost pluto[16393]: NAT-Traversal: Trying new style NAT-T
Jul  7 09:39:53 localhost pluto[16393]: NAT-Traversal: ESPINUDP(1) setup failed for new style NAT-T family IPv4 (errno=19)
Jul  7 09:39:53 localhost pluto[16393]: NAT-Traversal: Trying old style NAT-T
Jul  7 09:39:53 localhost pluto[16393]: adding interface eth0/eth0 192.168.25.77:500
Jul  7 09:39:53 localhost pluto[16393]: adding interface eth0/eth0 192.168.25.77:4500
Jul  7 09:39:53 localhost pluto[16393]: adding interface lo/lo 127.0.0.1:500
Jul  7 09:39:53 localhost pluto[16393]: adding interface lo/lo 127.0.0.1:4500
Jul  7 09:39:53 localhost pluto[16393]: adding interface lo/lo ::1:500
Jul  7 09:39:53 localhost pluto[16393]: loading secrets from "/etc/ipsec.secrets"
Jul  7 09:39:53 localhost pluto[16393]: loaded private key for keyid: PPK_RSA:AQOhkCrYj
Jul  7 09:39:58 localhost pluto[16393]: | base debugging = raw+crypt+parsing+emitting+control+lifecycle+klips+dns+oppo+controlmore+pfkey+nattraversal+x509
Jul  7 09:39:58 localhost pluto[16393]: | * processed 0 messages from cryptographic helpers 
Jul  7 09:39:58 localhost pluto[16393]: | next event EVENT_PENDING_DDNS in 54 seconds
Jul  7 09:39:58 localhost pluto[16393]: | next event EVENT_PENDING_DDNS in 54 seconds
Jul  7 09:40:52 localhost pluto[16393]: |  
Jul  7 09:40:52 localhost pluto[16393]: | next event EVENT_PENDING_DDNS in 0 seconds
Jul  7 09:40:52 localhost pluto[16393]: | *time to handle event
Jul  7 09:40:52 localhost pluto[16393]: | handling event EVENT_PENDING_DDNS
Jul  7 09:40:52 localhost pluto[16393]: | event after this is EVENT_PENDING_PHASE2 in 60 seconds
Jul  7 09:40:52 localhost pluto[16393]: | inserting event EVENT_PENDING_DDNS, timeout in 60 seconds
Jul  7 09:40:52 localhost pluto[16393]: | event added at head of queue
Jul  7 09:40:52 localhost pluto[16393]: | next event EVENT_PENDING_DDNS in 60 seconds
Jul  7 09:41:16 localhost pluto[16393]: |  
Jul  7 09:41:16 localhost pluto[16393]: | *received whack message
Jul  7 09:41:16 localhost pluto[16393]: | processing connection vpn-connection
Jul  7 09:41:16 localhost pluto[16393]: | kernel_alg_db_new() initial trans_cnt=90
Jul  7 09:41:16 localhost pluto[16393]: | kernel_alg_db_new() will return p_new->protoid=3, p_new->trans_cnt=1
Jul  7 09:41:16 localhost pluto[16393]: | kernel_alg_db_new()     trans[0]: transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=2
Jul  7 09:41:16 localhost pluto[16393]: | returning new proposal from esp_info
Jul  7 09:41:16 localhost pluto[16393]: | creating state object #1 at 0x8cfb5a0
Jul  7 09:41:16 localhost pluto[16393]: | processing connection vpn-connection
Jul  7 09:41:16 localhost pluto[16393]: | ICOOKIE:  1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:16 localhost pluto[16393]: | RCOOKIE:  00 00 00 00  00 00 00 00
Jul  7 09:41:16 localhost pluto[16393]: | state hash entry 12
Jul  7 09:41:16 localhost pluto[16393]: | inserting state object #1 on chain 12
Jul  7 09:41:16 localhost pluto[16393]: | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #1
Jul  7 09:41:16 localhost pluto[16393]: | event added at head of queue
Jul  7 09:41:16 localhost pluto[16393]: | processing connection vpn-connection
Jul  7 09:41:16 localhost pluto[16393]: | Queuing pending Quick Mode with 12.13.14.15 "vpn-connection"
Jul  7 09:41:16 localhost pluto[16393]: "vpn-connection" #1: initiating Main Mode
Jul  7 09:41:16 localhost pluto[16393]: | **emit ISAKMP Message:
Jul  7 09:41:16 localhost pluto[16393]: |    initiator cookie:
Jul  7 09:41:16 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:16 localhost pluto[16393]: |    responder cookie:
Jul  7 09:41:16 localhost pluto[16393]: |   00 00 00 00  00 00 00 00
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_SA
Jul  7 09:41:16 localhost pluto[16393]: |    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
Jul  7 09:41:16 localhost pluto[16393]: |    exchange type: ISAKMP_XCHG_IDPROT
Jul  7 09:41:16 localhost pluto[16393]: |    flags: none
Jul  7 09:41:16 localhost pluto[16393]: |    message ID:  00 00 00 00
Jul  7 09:41:16 localhost pluto[16393]: | ***emit ISAKMP Security Association Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_VID
Jul  7 09:41:16 localhost pluto[16393]: |    DOI: ISAKMP_DOI_IPSEC
Jul  7 09:41:16 localhost pluto[16393]: | ****emit IPsec DOI SIT:
Jul  7 09:41:16 localhost pluto[16393]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Jul  7 09:41:16 localhost pluto[16393]: | out_sa pcn: 0 has 1 valid proposals
Jul  7 09:41:16 localhost pluto[16393]: | out_sa pcn: 0 pn: 0<1 valid_count: 1 trans_cnt: 1
Jul  7 09:41:16 localhost pluto[16393]: | ****emit ISAKMP Proposal Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:16 localhost pluto[16393]: |    proposal number: 0
Jul  7 09:41:16 localhost pluto[16393]: |    protocol ID: PROTO_ISAKMP
Jul  7 09:41:16 localhost pluto[16393]: |    SPI size: 0
Jul  7 09:41:16 localhost pluto[16393]: |    number of transforms: 1
Jul  7 09:41:16 localhost pluto[16393]: | *****emit ISAKMP Transform Payload (ISAKMP):
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:16 localhost pluto[16393]: |    transform number: 0
Jul  7 09:41:16 localhost pluto[16393]: |    transform ID: KEY_IKE
Jul  7 09:41:16 localhost pluto[16393]: | ******emit ISAKMP Oakley attribute:
Jul  7 09:41:16 localhost pluto[16393]: |    af+type: OAKLEY_LIFE_TYPE
Jul  7 09:41:16 localhost pluto[16393]: |    length/value: 1
Jul  7 09:41:16 localhost pluto[16393]: |     [1 is OAKLEY_LIFE_SECONDS]
Jul  7 09:41:16 localhost pluto[16393]: | ******emit ISAKMP Oakley attribute:
Jul  7 09:41:16 localhost pluto[16393]: |    af+type: OAKLEY_LIFE_DURATION
Jul  7 09:41:16 localhost pluto[16393]: |    length/value: 3600
Jul  7 09:41:16 localhost pluto[16393]: | ******emit ISAKMP Oakley attribute:
Jul  7 09:41:16 localhost pluto[16393]: |    af+type: OAKLEY_ENCRYPTION_ALGORITHM
Jul  7 09:41:16 localhost pluto[16393]: |    length/value: 5
Jul  7 09:41:16 localhost pluto[16393]: |     [5 is OAKLEY_3DES_CBC]
Jul  7 09:41:16 localhost pluto[16393]: | ******emit ISAKMP Oakley attribute:
Jul  7 09:41:16 localhost pluto[16393]: |    af+type: OAKLEY_HASH_ALGORITHM
Jul  7 09:41:16 localhost pluto[16393]: |    length/value: 2
Jul  7 09:41:16 localhost pluto[16393]: |     [2 is OAKLEY_SHA1]
Jul  7 09:41:16 localhost pluto[16393]: | ******emit ISAKMP Oakley attribute:
Jul  7 09:41:16 localhost pluto[16393]: |    af+type: OAKLEY_AUTHENTICATION_METHOD
Jul  7 09:41:16 localhost pluto[16393]: |    length/value: 1
Jul  7 09:41:16 localhost pluto[16393]: |     [1 is OAKLEY_PRESHARED_KEY]
Jul  7 09:41:16 localhost pluto[16393]: | ******emit ISAKMP Oakley attribute:
Jul  7 09:41:16 localhost pluto[16393]: |    af+type: OAKLEY_GROUP_DESCRIPTION
Jul  7 09:41:16 localhost pluto[16393]: |    length/value: 2
Jul  7 09:41:16 localhost pluto[16393]: |     [2 is OAKLEY_GROUP_MODP1024]
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Transform Payload (ISAKMP): 32
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Proposal Payload: 40
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Security Association Payload: 52
Jul  7 09:41:16 localhost pluto[16393]: | ***emit ISAKMP Vendor ID Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_VID
Jul  7 09:41:16 localhost pluto[16393]: | emitting 12 raw bytes of Vendor ID into ISAKMP Vendor ID Payload
Jul  7 09:41:16 localhost pluto[16393]: | Vendor ID  4f 45 6c 6a  40 5d 72 54  4d 42 75 4d
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Vendor ID Payload: 16
Jul  7 09:41:16 localhost pluto[16393]: | out_vendorid(): sending [Dead Peer Detection]
Jul  7 09:41:16 localhost pluto[16393]: | ***emit ISAKMP Vendor ID Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_VID
Jul  7 09:41:16 localhost pluto[16393]: | emitting 16 raw bytes of V_ID into ISAKMP Vendor ID Payload
Jul  7 09:41:16 localhost pluto[16393]: | V_ID  af ca d7 13  68 a1 f1 c9  6b 86 96 fc  77 57 01 00
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Vendor ID Payload: 20
Jul  7 09:41:16 localhost pluto[16393]: | nat traversal enabled: 1
Jul  7 09:41:16 localhost pluto[16393]: | nat add vid. port: 1 nonike: 1
Jul  7 09:41:16 localhost pluto[16393]: | out_vendorid(): sending [RFC 3947]
Jul  7 09:41:16 localhost pluto[16393]: | ***emit ISAKMP Vendor ID Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_VID
Jul  7 09:41:16 localhost pluto[16393]: | emitting 16 raw bytes of V_ID into ISAKMP Vendor ID Payload
Jul  7 09:41:16 localhost pluto[16393]: | V_ID  4a 13 1c 81  07 03 58 45  5c 57 28 f2  0e 95 45 2f
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Vendor ID Payload: 20
Jul  7 09:41:16 localhost pluto[16393]: | out_vendorid(): sending [draft-ietf-ipsec-nat-t-ike-03]
Jul  7 09:41:16 localhost pluto[16393]: | ***emit ISAKMP Vendor ID Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_VID
Jul  7 09:41:16 localhost pluto[16393]: | emitting 16 raw bytes of V_ID into ISAKMP Vendor ID Payload
Jul  7 09:41:16 localhost pluto[16393]: | V_ID  7d 94 19 a6  53 10 ca 6f  2c 17 9d 92  15 52 9d 56
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Vendor ID Payload: 20
Jul  7 09:41:16 localhost pluto[16393]: | out_vendorid(): sending [draft-ietf-ipsec-nat-t-ike-02_n]
Jul  7 09:41:16 localhost pluto[16393]: | ***emit ISAKMP Vendor ID Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_VID
Jul  7 09:41:16 localhost pluto[16393]: | emitting 16 raw bytes of V_ID into ISAKMP Vendor ID Payload
Jul  7 09:41:16 localhost pluto[16393]: | V_ID  90 cb 80 91  3e bb 69 6e  08 63 81 b5  ec 42 7b 1f
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Vendor ID Payload: 20
Jul  7 09:41:16 localhost pluto[16393]: | out_vendorid(): sending [draft-ietf-ipsec-nat-t-ike-02]
Jul  7 09:41:16 localhost pluto[16393]: | ***emit ISAKMP Vendor ID Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_VID
Jul  7 09:41:16 localhost pluto[16393]: | emitting 16 raw bytes of V_ID into ISAKMP Vendor ID Payload
Jul  7 09:41:16 localhost pluto[16393]: | V_ID  cd 60 46 43  35 df 21 f8  7c fd b2 fc  68 b6 a4 48
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Vendor ID Payload: 20
Jul  7 09:41:16 localhost pluto[16393]: | out_vendorid(): sending [draft-ietf-ipsec-nat-t-ike-00]
Jul  7 09:41:16 localhost pluto[16393]: | ***emit ISAKMP Vendor ID Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:16 localhost pluto[16393]: | emitting 16 raw bytes of V_ID into ISAKMP Vendor ID Payload
Jul  7 09:41:16 localhost pluto[16393]: | V_ID  44 85 15 2d  18 b6 bb cd  0b e8 a8 46  95 79 dd cc
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Vendor ID Payload: 20
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Message: 216
Jul  7 09:41:16 localhost pluto[16393]: | sending 216 bytes for main_outI1 through eth0:500 to 12.13.14.15:500 (using #1)
Jul  7 09:41:16 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3  00 00 00 00  00 00 00 00
Jul  7 09:41:16 localhost pluto[16393]: |   01 10 02 00  00 00 00 00  00 00 00 d8  0d 00 00 34
Jul  7 09:41:16 localhost pluto[16393]: |   00 00 00 01  00 00 00 01  00 00 00 28  00 01 00 01
Jul  7 09:41:16 localhost pluto[16393]: |   00 00 00 20  00 01 00 00  80 0b 00 01  80 0c 0e 10
Jul  7 09:41:16 localhost pluto[16393]: |   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 02
Jul  7 09:41:16 localhost pluto[16393]: |   0d 00 00 10  4f 45 6c 6a  40 5d 72 54  4d 42 75 4d
Jul  7 09:41:16 localhost pluto[16393]: |   0d 00 00 14  af ca d7 13  68 a1 f1 c9  6b 86 96 fc
Jul  7 09:41:16 localhost pluto[16393]: |   77 57 01 00  0d 00 00 14  4a 13 1c 81  07 03 58 45
Jul  7 09:41:16 localhost pluto[16393]: |   5c 57 28 f2  0e 95 45 2f  0d 00 00 14  7d 94 19 a6
Jul  7 09:41:16 localhost pluto[16393]: |   53 10 ca 6f  2c 17 9d 92  15 52 9d 56  0d 00 00 14
Jul  7 09:41:16 localhost pluto[16393]: |   90 cb 80 91  3e bb 69 6e  08 63 81 b5  ec 42 7b 1f
Jul  7 09:41:16 localhost pluto[16393]: |   0d 00 00 14  cd 60 46 43  35 df 21 f8  7c fd b2 fc
Jul  7 09:41:16 localhost pluto[16393]: |   68 b6 a4 48  00 00 00 14  44 85 15 2d  18 b6 bb cd
Jul  7 09:41:16 localhost pluto[16393]: |   0b e8 a8 46  95 79 dd cc
Jul  7 09:41:16 localhost pluto[16393]: | deleting event for #1
Jul  7 09:41:16 localhost pluto[16393]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
Jul  7 09:41:16 localhost pluto[16393]: | event added at head of queue
Jul  7 09:41:16 localhost pluto[16393]: | * processed 0 messages from cryptographic helpers 
Jul  7 09:41:16 localhost pluto[16393]: | next event EVENT_RETRANSMIT in 10 seconds for #1
Jul  7 09:41:16 localhost pluto[16393]: | next event EVENT_RETRANSMIT in 10 seconds for #1
Jul  7 09:41:16 localhost pluto[16393]: |  
Jul  7 09:41:16 localhost pluto[16393]: | *received 112 bytes from 12.13.14.15:500 on eth0 (port=500)
Jul  7 09:41:16 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3  88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: |   01 10 02 00  00 00 00 00  00 00 00 70  0d 00 00 34
Jul  7 09:41:16 localhost pluto[16393]: |   00 00 00 01  00 00 00 01  00 00 00 28  00 01 00 01
Jul  7 09:41:16 localhost pluto[16393]: |   00 00 00 20  00 01 00 00  80 0b 00 01  80 0c 0e 10
Jul  7 09:41:16 localhost pluto[16393]: |   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 02
Jul  7 09:41:16 localhost pluto[16393]: |   0d 00 00 0c  42 4e 45 53  00 00 00 09  00 00 00 14
Jul  7 09:41:16 localhost pluto[16393]: |   af ca d7 13  68 a1 f1 c9  6b 86 96 fc  77 57 01 00
Jul  7 09:41:16 localhost pluto[16393]: | **parse ISAKMP Message:
Jul  7 09:41:16 localhost pluto[16393]: |    initiator cookie:
Jul  7 09:41:16 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:16 localhost pluto[16393]: |    responder cookie:
Jul  7 09:41:16 localhost pluto[16393]: |   88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_SA
Jul  7 09:41:16 localhost pluto[16393]: |    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
Jul  7 09:41:16 localhost pluto[16393]: |    exchange type: ISAKMP_XCHG_IDPROT
Jul  7 09:41:16 localhost pluto[16393]: |    flags: none
Jul  7 09:41:16 localhost pluto[16393]: |    message ID:  00 00 00 00
Jul  7 09:41:16 localhost pluto[16393]: |    length: 112
Jul  7 09:41:16 localhost pluto[16393]: |  processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
Jul  7 09:41:16 localhost pluto[16393]: | ICOOKIE:  1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:16 localhost pluto[16393]: | RCOOKIE:  88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: | state hash entry 30
Jul  7 09:41:16 localhost pluto[16393]: | v1 state object not found
Jul  7 09:41:16 localhost pluto[16393]: | ICOOKIE:  1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:16 localhost pluto[16393]: | RCOOKIE:  00 00 00 00  00 00 00 00
Jul  7 09:41:16 localhost pluto[16393]: | state hash entry 12
Jul  7 09:41:16 localhost pluto[16393]: | v1 peer and cookies match on #1, provided msgid 00000000 vs 00000000
Jul  7 09:41:16 localhost pluto[16393]: | v1 state object #1 found, in STATE_MAIN_I1
Jul  7 09:41:16 localhost pluto[16393]: | processing connection vpn-connection
Jul  7 09:41:16 localhost pluto[16393]: | got payload 0x2(ISAKMP_NEXT_SA) needed: 0x2 opt: 0x2080
Jul  7 09:41:16 localhost pluto[16393]: | ***parse ISAKMP Security Association Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_VID
Jul  7 09:41:16 localhost pluto[16393]: |    length: 52
Jul  7 09:41:16 localhost pluto[16393]: |    DOI: ISAKMP_DOI_IPSEC
Jul  7 09:41:16 localhost pluto[16393]: | got payload 0x2000(ISAKMP_NEXT_VID) needed: 0x0 opt: 0x2080
Jul  7 09:41:16 localhost pluto[16393]: | ***parse ISAKMP Vendor ID Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_VID
Jul  7 09:41:16 localhost pluto[16393]: |    length: 12
Jul  7 09:41:16 localhost pluto[16393]: | got payload 0x2000(ISAKMP_NEXT_VID) needed: 0x0 opt: 0x2080
Jul  7 09:41:16 localhost pluto[16393]: | ***parse ISAKMP Vendor ID Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:16 localhost pluto[16393]: |    length: 20
Jul  7 09:41:16 localhost pluto[16393]: "vpn-connection" #1: ignoring unknown Vendor ID payload [424e455300000009]
Jul  7 09:41:16 localhost pluto[16393]: "vpn-connection" #1: received Vendor ID payload [Dead Peer Detection]
Jul  7 09:41:16 localhost pluto[16393]: | ****parse IPsec DOI SIT:
Jul  7 09:41:16 localhost pluto[16393]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Jul  7 09:41:16 localhost pluto[16393]: | ****parse ISAKMP Proposal Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:16 localhost pluto[16393]: |    length: 40
Jul  7 09:41:16 localhost pluto[16393]: |    proposal number: 0
Jul  7 09:41:16 localhost pluto[16393]: |    protocol ID: PROTO_ISAKMP
Jul  7 09:41:16 localhost pluto[16393]: |    SPI size: 0
Jul  7 09:41:16 localhost pluto[16393]: |    number of transforms: 1
Jul  7 09:41:16 localhost pluto[16393]: | *****parse ISAKMP Transform Payload (ISAKMP):
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:16 localhost pluto[16393]: |    length: 32
Jul  7 09:41:16 localhost pluto[16393]: |    transform number: 0
Jul  7 09:41:16 localhost pluto[16393]: |    transform ID: KEY_IKE
Jul  7 09:41:16 localhost pluto[16393]: | ******parse ISAKMP Oakley attribute:
Jul  7 09:41:16 localhost pluto[16393]: |    af+type: OAKLEY_LIFE_TYPE
Jul  7 09:41:16 localhost pluto[16393]: |    length/value: 1
Jul  7 09:41:16 localhost pluto[16393]: |    [1 is OAKLEY_LIFE_SECONDS]
Jul  7 09:41:16 localhost pluto[16393]: | ******parse ISAKMP Oakley attribute:
Jul  7 09:41:16 localhost pluto[16393]: |    af+type: OAKLEY_LIFE_DURATION
Jul  7 09:41:16 localhost pluto[16393]: |    length/value: 3600
Jul  7 09:41:16 localhost pluto[16393]: | ******parse ISAKMP Oakley attribute:
Jul  7 09:41:16 localhost pluto[16393]: |    af+type: OAKLEY_ENCRYPTION_ALGORITHM
Jul  7 09:41:16 localhost pluto[16393]: |    length/value: 5
Jul  7 09:41:16 localhost pluto[16393]: |    [5 is OAKLEY_3DES_CBC]
Jul  7 09:41:16 localhost pluto[16393]: | ike_alg_enc_ok(ealg=5,key_len=0): blocksize=8, keyminlen=192, keydeflen=192, keymaxlen=192, ret=1
Jul  7 09:41:16 localhost pluto[16393]: | ******parse ISAKMP Oakley attribute:
Jul  7 09:41:16 localhost pluto[16393]: |    af+type: OAKLEY_HASH_ALGORITHM
Jul  7 09:41:16 localhost pluto[16393]: |    length/value: 2
Jul  7 09:41:16 localhost pluto[16393]: |    [2 is OAKLEY_SHA1]
Jul  7 09:41:16 localhost pluto[16393]: | ******parse ISAKMP Oakley attribute:
Jul  7 09:41:16 localhost pluto[16393]: |    af+type: OAKLEY_AUTHENTICATION_METHOD
Jul  7 09:41:16 localhost pluto[16393]: |    length/value: 1
Jul  7 09:41:16 localhost pluto[16393]: |    [1 is OAKLEY_PRESHARED_KEY]
Jul  7 09:41:16 localhost pluto[16393]: | started looking for secret for 192.168.25.77->12.13.14.15 of kind PPK_PSK
Jul  7 09:41:16 localhost pluto[16393]: | actually looking for secret for 192.168.25.77->12.13.14.15 of kind PPK_PSK
Jul  7 09:41:16 localhost pluto[16393]: | line 19: key type PPK_PSK(192.168.25.77) to type PPK_PSK 
Jul  7 09:41:16 localhost pluto[16393]: | 1: compared key 12.13.14.15 to 192.168.25.77 / 12.13.14.15 -> 4
Jul  7 09:41:16 localhost pluto[16393]: | 2: compared key 192.168.25.77 to 192.168.25.77 / 12.13.14.15 -> 12
Jul  7 09:41:16 localhost pluto[16393]: | line 19: match=12 
Jul  7 09:41:16 localhost pluto[16393]: | best_match 0>12 best=0x8cfb4a8 (line=19)
Jul  7 09:41:16 localhost pluto[16393]: | line 17: key type PPK_PSK(192.168.25.77) to type PPK_PSK 
Jul  7 09:41:16 localhost pluto[16393]: | 1: compared key 12.13.14.15 to 192.168.25.77 / 12.13.14.15 -> 4
Jul  7 09:41:16 localhost pluto[16393]: | 2: compared key "my local-static-ip" to 192.168.25.77 / 12.13.14.15 -> 4
Jul  7 09:41:16 localhost pluto[16393]: | line 17: match=4 
Jul  7 09:41:16 localhost pluto[16393]: | line 1: key type PPK_PSK(192.168.25.77) to type PPK_RSA 
Jul  7 09:41:16 localhost pluto[16393]: | concluding with best_match=12 best=0x8cfb4a8 (lineno=19)
Jul  7 09:41:16 localhost pluto[16393]: | ******parse ISAKMP Oakley attribute:
Jul  7 09:41:16 localhost pluto[16393]: |    af+type: OAKLEY_GROUP_DESCRIPTION
Jul  7 09:41:16 localhost pluto[16393]: |    length/value: 2
Jul  7 09:41:16 localhost pluto[16393]: |    [2 is OAKLEY_GROUP_MODP1024]
Jul  7 09:41:16 localhost pluto[16393]: | Oakley Transform 0 accepted
Jul  7 09:41:16 localhost pluto[16393]: | sender checking NAT-t: 1 and 0
Jul  7 09:41:16 localhost pluto[16393]: | 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
Jul  7 09:41:16 localhost pluto[16393]: | asking helper 0 to do build_kenonce op on seq: 1 (len=2668, pcw_work=1)
Jul  7 09:41:16 localhost pluto[16393]: | crypto helper write of request: cnt=2668<wlen=2668.  
Jul  7 09:41:16 localhost pluto[16393]: | deleting event for #1
Jul  7 09:41:16 localhost pluto[16393]: | inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #1
Jul  7 09:41:16 localhost pluto[16393]: | event added after event EVENT_PENDING_PHASE2
Jul  7 09:41:16 localhost pluto[16393]: | complete state transition with STF_SUSPEND
Jul  7 09:41:16 localhost pluto[16393]: | * processed 0 messages from cryptographic helpers 
Jul  7 09:41:16 localhost pluto[16393]: | next event EVENT_PENDING_DDNS in 36 seconds
Jul  7 09:41:16 localhost pluto[16393]: | next event EVENT_PENDING_DDNS in 36 seconds
Jul  7 09:41:16 localhost pluto[16393]: |  
Jul  7 09:41:16 localhost pluto[16393]: | helper 0 has finished work (cnt now 1)
Jul  7 09:41:16 localhost pluto[16393]: | helper 0 replies to id: q#1
Jul  7 09:41:16 localhost pluto[16393]: | calling callback function 0x806bf4e
Jul  7 09:41:16 localhost pluto[16393]: | main inR1_outI2: calculated ke+nonce, sending I2
Jul  7 09:41:16 localhost pluto[16393]: | processing connection vpn-connection
Jul  7 09:41:16 localhost pluto[16393]: | **emit ISAKMP Message:
Jul  7 09:41:16 localhost pluto[16393]: |    initiator cookie:
Jul  7 09:41:16 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:16 localhost pluto[16393]: |    responder cookie:
Jul  7 09:41:16 localhost pluto[16393]: |   88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_KE
Jul  7 09:41:16 localhost pluto[16393]: |    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
Jul  7 09:41:16 localhost pluto[16393]: |    exchange type: ISAKMP_XCHG_IDPROT
Jul  7 09:41:16 localhost pluto[16393]: |    flags: none
Jul  7 09:41:16 localhost pluto[16393]: |    message ID:  00 00 00 00
Jul  7 09:41:16 localhost pluto[16393]: | ***emit ISAKMP Key Exchange Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONCE
Jul  7 09:41:16 localhost pluto[16393]: | emitting 128 raw bytes of keyex value into ISAKMP Key Exchange Payload
Jul  7 09:41:16 localhost pluto[16393]: | keyex value  15 92 6c 28  12 72 86 ac  f5 d6 ac fa  24 ed 8d 33
Jul  7 09:41:16 localhost pluto[16393]: | keyex value  f0 62 77 07  43 3a b4 b8  70 d5 71 7f  61 77 48 0d
Jul  7 09:41:16 localhost pluto[16393]: | keyex value  98 16 a6 04  32 29 ab 31  15 1e a4 77  d0 e7 18 96
Jul  7 09:41:16 localhost pluto[16393]: | keyex value  cd 1e 4a 14  e3 a7 6d e0  09 16 4e c4  35 cb bf e2
Jul  7 09:41:16 localhost pluto[16393]: | keyex value  7c bb 9f 5e  9b 23 cb e4  9a 81 8a 4f  9b da cc 07
Jul  7 09:41:16 localhost pluto[16393]: | keyex value  f4 7e 87 89  64 dc fc be  96 e9 48 90  0b 1a 7e 24
Jul  7 09:41:16 localhost pluto[16393]: | keyex value  a9 85 b2 92  14 28 eb e8  3b 51 2f bb  c3 1c f0 d8
Jul  7 09:41:16 localhost pluto[16393]: | keyex value  32 f4 fd a9  f6 be 6c 25  b7 ed 01 12  25 cb f2 95
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Key Exchange Payload: 132
Jul  7 09:41:16 localhost pluto[16393]: | ***emit ISAKMP Nonce Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:16 localhost pluto[16393]: | emitting 16 raw bytes of Ni into ISAKMP Nonce Payload
Jul  7 09:41:16 localhost pluto[16393]: | Ni  03 72 5c c4  0e 64 ba e2  38 73 51 8e  f5 5c 00 4c
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Nonce Payload: 20
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Message: 180
Jul  7 09:41:16 localhost pluto[16393]: | ICOOKIE:  1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:16 localhost pluto[16393]: | RCOOKIE:  00 00 00 00  00 00 00 00
Jul  7 09:41:16 localhost pluto[16393]: | state hash entry 12
Jul  7 09:41:16 localhost pluto[16393]: | ICOOKIE:  1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:16 localhost pluto[16393]: | RCOOKIE:  88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: | state hash entry 30
Jul  7 09:41:16 localhost pluto[16393]: | inserting state object #1 on chain 30
Jul  7 09:41:16 localhost pluto[16393]: | complete state transition with STF_OK
Jul  7 09:41:16 localhost pluto[16393]: "vpn-connection" #1: transition from state STATE_MAIN_I1 to state STATE_MAIN_I2
Jul  7 09:41:16 localhost pluto[16393]: | deleting event for #1
Jul  7 09:41:16 localhost pluto[16393]: | sending reply packet to 12.13.14.15:500 (from port 500)
Jul  7 09:41:16 localhost pluto[16393]: | sending 180 bytes for STATE_MAIN_I1 through eth0:500 to 12.13.14.15:500 (using #1)
Jul  7 09:41:16 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3  88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: |   04 10 02 00  00 00 00 00  00 00 00 b4  0a 00 00 84
Jul  7 09:41:16 localhost pluto[16393]: |   15 92 6c 28  12 72 86 ac  f5 d6 ac fa  24 ed 8d 33
Jul  7 09:41:16 localhost pluto[16393]: |   f0 62 77 07  43 3a b4 b8  70 d5 71 7f  61 77 48 0d
Jul  7 09:41:16 localhost pluto[16393]: |   98 16 a6 04  32 29 ab 31  15 1e a4 77  d0 e7 18 96
Jul  7 09:41:16 localhost pluto[16393]: |   cd 1e 4a 14  e3 a7 6d e0  09 16 4e c4  35 cb bf e2
Jul  7 09:41:16 localhost pluto[16393]: |   7c bb 9f 5e  9b 23 cb e4  9a 81 8a 4f  9b da cc 07
Jul  7 09:41:16 localhost pluto[16393]: |   f4 7e 87 89  64 dc fc be  96 e9 48 90  0b 1a 7e 24
Jul  7 09:41:16 localhost pluto[16393]: |   a9 85 b2 92  14 28 eb e8  3b 51 2f bb  c3 1c f0 d8
Jul  7 09:41:16 localhost pluto[16393]: |   32 f4 fd a9  f6 be 6c 25  b7 ed 01 12  25 cb f2 95
Jul  7 09:41:16 localhost pluto[16393]: |   00 00 00 14  03 72 5c c4  0e 64 ba e2  38 73 51 8e
Jul  7 09:41:16 localhost pluto[16393]: |   f5 5c 00 4c
Jul  7 09:41:16 localhost pluto[16393]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
Jul  7 09:41:16 localhost pluto[16393]: | event added at head of queue
Jul  7 09:41:16 localhost pluto[16393]: "vpn-connection" #1: STATE_MAIN_I2: sent MI2, expecting MR2
Jul  7 09:41:16 localhost pluto[16393]: | modecfg pull: noquirk policy:push not-client
Jul  7 09:41:16 localhost pluto[16393]: | phase 1 is done, looking for phase 2 to unpend
Jul  7 09:41:16 localhost pluto[16393]: | * processed 1 messages from cryptographic helpers 
Jul  7 09:41:16 localhost pluto[16393]: | next event EVENT_RETRANSMIT in 10 seconds for #1
Jul  7 09:41:16 localhost pluto[16393]: | next event EVENT_RETRANSMIT in 10 seconds for #1
Jul  7 09:41:16 localhost pluto[16393]: |  
Jul  7 09:41:16 localhost pluto[16393]: | *received 184 bytes from 12.13.14.15:500 on eth0 (port=500)
Jul  7 09:41:16 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3  88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: |   04 10 02 00  00 00 00 00  00 00 00 b8  0a 00 00 84
Jul  7 09:41:16 localhost pluto[16393]: |   55 83 e0 27  12 0f 00 16  77 82 5f 75  79 b9 b8 13
Jul  7 09:41:16 localhost pluto[16393]: |   dd 0d 7b 96  e4 2b c5 ec  3f 69 6b d8  ca 8c d4 ed
Jul  7 09:41:16 localhost pluto[16393]: |   41 05 d1 90  26 d4 a1 ce  d8 33 21 87  bc af d7 8c
Jul  7 09:41:16 localhost pluto[16393]: |   06 f1 16 3c  51 c3 47 7f  ce 9e ac 44  a2 53 fc da
Jul  7 09:41:16 localhost pluto[16393]: |   30 0d df ff  77 15 5f 6d  87 04 64 1f  0b f0 fb 6c
Jul  7 09:41:16 localhost pluto[16393]: |   2d 34 66 22  45 4e b7 02  35 2a 85 80  b6 7a 52 b5
Jul  7 09:41:16 localhost pluto[16393]: |   3a d7 c0 b7  0e e6 98 c5  74 71 ea a8  ea af 32 a6
Jul  7 09:41:16 localhost pluto[16393]: |   4a 9c 3d a0  cd 15 56 5d  2c d0 1d 4a  0a e2 1e 84
Jul  7 09:41:16 localhost pluto[16393]: |   00 00 00 18  f4 bf ac b1  32 b3 54 04  71 c1 e2 63
Jul  7 09:41:16 localhost pluto[16393]: |   d4 d4 2c 40  b8 95 50 16
Jul  7 09:41:16 localhost pluto[16393]: | **parse ISAKMP Message:
Jul  7 09:41:16 localhost pluto[16393]: |    initiator cookie:
Jul  7 09:41:16 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:16 localhost pluto[16393]: |    responder cookie:
Jul  7 09:41:16 localhost pluto[16393]: |   88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_KE
Jul  7 09:41:16 localhost pluto[16393]: |    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
Jul  7 09:41:16 localhost pluto[16393]: |    exchange type: ISAKMP_XCHG_IDPROT
Jul  7 09:41:16 localhost pluto[16393]: |    flags: none
Jul  7 09:41:16 localhost pluto[16393]: |    message ID:  00 00 00 00
Jul  7 09:41:16 localhost pluto[16393]: |    length: 184
Jul  7 09:41:16 localhost pluto[16393]: |  processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
Jul  7 09:41:16 localhost pluto[16393]: | ICOOKIE:  1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:16 localhost pluto[16393]: | RCOOKIE:  88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: | state hash entry 30
Jul  7 09:41:16 localhost pluto[16393]: | v1 peer and cookies match on #1, provided msgid 00000000 vs 00000000
Jul  7 09:41:16 localhost pluto[16393]: | v1 state object #1 found, in STATE_MAIN_I2
Jul  7 09:41:16 localhost pluto[16393]: | processing connection vpn-connection
Jul  7 09:41:16 localhost pluto[16393]: | got payload 0x10(ISAKMP_NEXT_KE) needed: 0x410 opt: 0x102080
Jul  7 09:41:16 localhost pluto[16393]: | ***parse ISAKMP Key Exchange Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONCE
Jul  7 09:41:16 localhost pluto[16393]: |    length: 132
Jul  7 09:41:16 localhost pluto[16393]: | got payload 0x400(ISAKMP_NEXT_NONCE) needed: 0x400 opt: 0x102080
Jul  7 09:41:16 localhost pluto[16393]: | ***parse ISAKMP Nonce Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:16 localhost pluto[16393]: |    length: 24
Jul  7 09:41:16 localhost pluto[16393]: | **emit ISAKMP Message:
Jul  7 09:41:16 localhost pluto[16393]: |    initiator cookie:
Jul  7 09:41:16 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:16 localhost pluto[16393]: |    responder cookie:
Jul  7 09:41:16 localhost pluto[16393]: |   88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_ID
Jul  7 09:41:16 localhost pluto[16393]: |    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
Jul  7 09:41:16 localhost pluto[16393]: |    exchange type: ISAKMP_XCHG_IDPROT
Jul  7 09:41:16 localhost pluto[16393]: |    flags: ISAKMP_FLAG_ENCRYPTION
Jul  7 09:41:16 localhost pluto[16393]: |    message ID:  00 00 00 00
Jul  7 09:41:16 localhost pluto[16393]: | DH public value received:
Jul  7 09:41:16 localhost pluto[16393]: |   55 83 e0 27  12 0f 00 16  77 82 5f 75  79 b9 b8 13
Jul  7 09:41:16 localhost pluto[16393]: |   dd 0d 7b 96  e4 2b c5 ec  3f 69 6b d8  ca 8c d4 ed
Jul  7 09:41:16 localhost pluto[16393]: |   41 05 d1 90  26 d4 a1 ce  d8 33 21 87  bc af d7 8c
Jul  7 09:41:16 localhost pluto[16393]: |   06 f1 16 3c  51 c3 47 7f  ce 9e ac 44  a2 53 fc da
Jul  7 09:41:16 localhost pluto[16393]: |   30 0d df ff  77 15 5f 6d  87 04 64 1f  0b f0 fb 6c
Jul  7 09:41:16 localhost pluto[16393]: |   2d 34 66 22  45 4e b7 02  35 2a 85 80  b6 7a 52 b5
Jul  7 09:41:16 localhost pluto[16393]: |   3a d7 c0 b7  0e e6 98 c5  74 71 ea a8  ea af 32 a6
Jul  7 09:41:16 localhost pluto[16393]: |   4a 9c 3d a0  cd 15 56 5d  2c d0 1d 4a  0a e2 1e 84
Jul  7 09:41:16 localhost pluto[16393]: | started looking for secret for 192.168.25.77->12.13.14.15 of kind PPK_PSK
Jul  7 09:41:16 localhost pluto[16393]: | actually looking for secret for 192.168.25.77->12.13.14.15 of kind PPK_PSK
Jul  7 09:41:16 localhost pluto[16393]: | line 19: key type PPK_PSK(192.168.25.77) to type PPK_PSK 
Jul  7 09:41:16 localhost pluto[16393]: | 1: compared key 12.13.14.15 to 192.168.25.77 / 12.13.14.15 -> 4
Jul  7 09:41:16 localhost pluto[16393]: | 2: compared key 192.168.25.77 to 192.168.25.77 / 12.13.14.15 -> 12
Jul  7 09:41:16 localhost pluto[16393]: | line 19: match=12 
Jul  7 09:41:16 localhost pluto[16393]: | best_match 0>12 best=0x8cfb4a8 (line=19)
Jul  7 09:41:16 localhost pluto[16393]: | line 17: key type PPK_PSK(192.168.25.77) to type PPK_PSK 
Jul  7 09:41:16 localhost pluto[16393]: | 1: compared key 12.13.14.15 to 192.168.25.77 / 12.13.14.15 -> 4
Jul  7 09:41:16 localhost pluto[16393]: | 2: compared key "my local static ip" to 192.168.25.77 / 12.13.14.15 -> 4
Jul  7 09:41:16 localhost pluto[16393]: | line 17: match=4 
Jul  7 09:41:16 localhost pluto[16393]: | line 1: key type PPK_PSK(192.168.25.77) to type PPK_RSA 
Jul  7 09:41:16 localhost pluto[16393]: | concluding with best_match=12 best=0x8cfb4a8 (lineno=19)
Jul  7 09:41:16 localhost pluto[16393]: | parent1 type: 7 group: 2 len: 2668 
Jul  7 09:41:16 localhost pluto[16393]: | 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
Jul  7 09:41:16 localhost pluto[16393]: | asking helper 0 to do compute dh+iv op on seq: 2 (len=2668, pcw_work=1)
Jul  7 09:41:16 localhost pluto[16393]: | crypto helper write of request: cnt=2668<wlen=2668.  
Jul  7 09:41:16 localhost pluto[16393]: | deleting event for #1
Jul  7 09:41:16 localhost pluto[16393]: | inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #1
Jul  7 09:41:16 localhost pluto[16393]: | event added after event EVENT_PENDING_PHASE2
Jul  7 09:41:16 localhost pluto[16393]: | complete state transition with STF_SUSPEND
Jul  7 09:41:16 localhost pluto[16393]: | * processed 0 messages from cryptographic helpers 
Jul  7 09:41:16 localhost pluto[16393]: | next event EVENT_PENDING_DDNS in 36 seconds
Jul  7 09:41:16 localhost pluto[16393]: | next event EVENT_PENDING_DDNS in 36 seconds
Jul  7 09:41:16 localhost pluto[16393]: |  
Jul  7 09:41:16 localhost pluto[16393]: | helper 0 has finished work (cnt now 1)
Jul  7 09:41:16 localhost pluto[16393]: | helper 0 replies to id: q#2
Jul  7 09:41:16 localhost pluto[16393]: | calling callback function 0x806d94e
Jul  7 09:41:16 localhost pluto[16393]: | main inR2_outI3: calculated DH, sending R1
Jul  7 09:41:16 localhost pluto[16393]: | processing connection vpn-connection
Jul  7 09:41:16 localhost pluto[16393]: | thinking about whether to send my certificate:
Jul  7 09:41:16 localhost pluto[16393]: |   I have RSA key: OAKLEY_PRESHARED_KEY cert.type: CERT_NONE 
Jul  7 09:41:16 localhost pluto[16393]: |   sendcert: CERT_ALWAYSSEND and I did not get a certificate request 
Jul  7 09:41:16 localhost pluto[16393]: |   so do not send cert.
Jul  7 09:41:16 localhost pluto[16393]: | I did not send a certificate because digital signatures are not being used. (PSK)
Jul  7 09:41:16 localhost pluto[16393]: |  I am not sending a certificate request
Jul  7 09:41:16 localhost pluto[16393]: | ***emit ISAKMP Identification Payload (IPsec DOI):
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_HASH
Jul  7 09:41:16 localhost pluto[16393]: |    ID type: ID_IPV4_ADDR
Jul  7 09:41:16 localhost pluto[16393]: |    Protocol ID: 0
Jul  7 09:41:16 localhost pluto[16393]: |    port: 0
Jul  7 09:41:16 localhost pluto[16393]: | emitting 4 raw bytes of my identity into ISAKMP Identification Payload (IPsec DOI)
Jul  7 09:41:16 localhost pluto[16393]: | my identity  0a 80 02 94
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Identification Payload (IPsec DOI): 12
Jul  7 09:41:16 localhost pluto[16393]: | hashing 48 bytes of SA
Jul  7 09:41:16 localhost pluto[16393]: | ***emit ISAKMP Hash Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:16 localhost pluto[16393]: | emitting 20 raw bytes of HASH_I into ISAKMP Hash Payload
Jul  7 09:41:16 localhost pluto[16393]: | HASH_I  ac 24 c0 4c  3b 81 8f 59  57 cd e6 1d  f3 be 82 0f
Jul  7 09:41:16 localhost pluto[16393]: | HASH_I  ad 55 a2 d1
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Hash Payload: 24
Jul  7 09:41:16 localhost pluto[16393]: | encrypting:
Jul  7 09:41:16 localhost pluto[16393]: |   08 00 00 0c  01 00 00 00  0a 80 02 94  00 00 00 18
Jul  7 09:41:16 localhost pluto[16393]: |   ac 24 c0 4c  3b 81 8f 59  57 cd e6 1d  f3 be 82 0f
Jul  7 09:41:16 localhost pluto[16393]: |   ad 55 a2 d1
Jul  7 09:41:16 localhost pluto[16393]: | IV:
Jul  7 09:41:16 localhost pluto[16393]: |   cc 4e eb 33  0b 9b b3 04  60 fc ed 37  64 5d 9c 00
Jul  7 09:41:16 localhost pluto[16393]: |   a7 8b a7 50
Jul  7 09:41:16 localhost pluto[16393]: | unpadded size is: 36
Jul  7 09:41:16 localhost pluto[16393]: | emitting 4 zero bytes of encryption padding into ISAKMP Message
Jul  7 09:41:16 localhost pluto[16393]: | encrypting 40 using OAKLEY_3DES_CBC
Jul  7 09:41:16 localhost pluto[16393]: | next IV:  53 8b 3a f2  be 4d 24 b1
Jul  7 09:41:16 localhost pluto[16393]: | emitting length of ISAKMP Message: 68
Jul  7 09:41:16 localhost pluto[16393]: | complete state transition with STF_OK
Jul  7 09:41:16 localhost pluto[16393]: "vpn-connection" #1: transition from state STATE_MAIN_I2 to state STATE_MAIN_I3
Jul  7 09:41:16 localhost pluto[16393]: | deleting event for #1
Jul  7 09:41:16 localhost pluto[16393]: | sending reply packet to 12.13.14.15:500 (from port 500)
Jul  7 09:41:16 localhost pluto[16393]: | sending 68 bytes for STATE_MAIN_I2 through eth0:500 to 12.13.14.15:500 (using #1)
Jul  7 09:41:16 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3  88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: |   05 10 02 01  00 00 00 00  00 00 00 44  c8 52 73 6a
Jul  7 09:41:16 localhost pluto[16393]: |   f7 66 2d e2  4d 3d ce c3  0b bb 8d ce  f2 05 0a e2
Jul  7 09:41:16 localhost pluto[16393]: |   43 b1 63 da  c2 36 71 56  99 6c e5 38  53 8b 3a f2
Jul  7 09:41:16 localhost pluto[16393]: |   be 4d 24 b1
Jul  7 09:41:16 localhost pluto[16393]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
Jul  7 09:41:16 localhost pluto[16393]: | event added at head of queue
Jul  7 09:41:16 localhost pluto[16393]: "vpn-connection" #1: STATE_MAIN_I3: sent MI3, expecting MR3
Jul  7 09:41:16 localhost pluto[16393]: | modecfg pull: noquirk policy:push not-client
Jul  7 09:41:16 localhost pluto[16393]: | phase 1 is done, looking for phase 2 to unpend
Jul  7 09:41:16 localhost pluto[16393]: | * processed 1 messages from cryptographic helpers 
Jul  7 09:41:16 localhost pluto[16393]: | next event EVENT_RETRANSMIT in 10 seconds for #1
Jul  7 09:41:16 localhost pluto[16393]: | next event EVENT_RETRANSMIT in 10 seconds for #1
Jul  7 09:41:16 localhost pluto[16393]: |  
Jul  7 09:41:16 localhost pluto[16393]: | *received 92 bytes from 12.13.14.15:500 on eth0 (port=500)
Jul  7 09:41:16 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3  88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: |   05 10 02 01  00 00 00 00  00 00 00 5c  3e 3d d5 e6
Jul  7 09:41:16 localhost pluto[16393]: |   ef 23 3f 38  81 c9 97 69  68 2c ff d9  23 fd f6 6a
Jul  7 09:41:16 localhost pluto[16393]: |   e5 30 b7 e8  a3 d1 29 e4  18 d2 6a a2  4e dd be 6a
Jul  7 09:41:16 localhost pluto[16393]: |   9a 8a 74 aa  e1 54 97 24  b1 f7 bc b7  fe d3 0c 90
Jul  7 09:41:16 localhost pluto[16393]: |   4e 19 d5 09  9c 26 ce 6a  73 a6 1a c6
Jul  7 09:41:16 localhost pluto[16393]: | **parse ISAKMP Message:
Jul  7 09:41:16 localhost pluto[16393]: |    initiator cookie:
Jul  7 09:41:16 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:16 localhost pluto[16393]: |    responder cookie:
Jul  7 09:41:16 localhost pluto[16393]: |   88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_ID
Jul  7 09:41:16 localhost pluto[16393]: |    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
Jul  7 09:41:16 localhost pluto[16393]: |    exchange type: ISAKMP_XCHG_IDPROT
Jul  7 09:41:16 localhost pluto[16393]: |    flags: ISAKMP_FLAG_ENCRYPTION
Jul  7 09:41:16 localhost pluto[16393]: |    message ID:  00 00 00 00
Jul  7 09:41:16 localhost pluto[16393]: |    length: 92
Jul  7 09:41:16 localhost pluto[16393]: |  processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
Jul  7 09:41:16 localhost pluto[16393]: | ICOOKIE:  1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:16 localhost pluto[16393]: | RCOOKIE:  88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: | state hash entry 30
Jul  7 09:41:16 localhost pluto[16393]: | v1 peer and cookies match on #1, provided msgid 00000000 vs 00000000
Jul  7 09:41:16 localhost pluto[16393]: | v1 state object #1 found, in STATE_MAIN_I3
Jul  7 09:41:16 localhost pluto[16393]: | processing connection vpn-connection
Jul  7 09:41:16 localhost pluto[16393]: | received encrypted packet from 12.13.14.15:500
Jul  7 09:41:16 localhost pluto[16393]: | decrypting 64 bytes using algorithm OAKLEY_3DES_CBC
Jul  7 09:41:16 localhost pluto[16393]: | decrypted:
Jul  7 09:41:16 localhost pluto[16393]: |   08 00 00 0c  01 00 00 00  c7 e5 be 08  0b 00 00 18
Jul  7 09:41:16 localhost pluto[16393]: |   75 60 bd 7c  c1 72 48 42  e4 a4 32 d0  c3 a3 6d 73
Jul  7 09:41:16 localhost pluto[16393]: |   56 93 9e f6  00 00 00 1c  00 00 00 01  01 10 60 02
Jul  7 09:41:16 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3  88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: | next IV:  9c 26 ce 6a  73 a6 1a c6
Jul  7 09:41:16 localhost pluto[16393]: | got payload 0x20(ISAKMP_NEXT_ID) needed: 0x120 opt: 0x2080
Jul  7 09:41:16 localhost pluto[16393]: | ***parse ISAKMP Identification Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_HASH
Jul  7 09:41:16 localhost pluto[16393]: |    length: 12
Jul  7 09:41:16 localhost pluto[16393]: |    ID type: ID_IPV4_ADDR
Jul  7 09:41:16 localhost pluto[16393]: |    DOI specific A: 0
Jul  7 09:41:16 localhost pluto[16393]: |    DOI specific B: 0
Jul  7 09:41:16 localhost pluto[16393]: |      obj:   c7 e5 be 08  0b 00 00 18  75 60 bd 7c
Jul  7 09:41:16 localhost pluto[16393]: | got payload 0x100(ISAKMP_NEXT_HASH) needed: 0x100 opt: 0x2080
Jul  7 09:41:16 localhost pluto[16393]: | ***parse ISAKMP Hash Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_N
Jul  7 09:41:16 localhost pluto[16393]: |    length: 24
Jul  7 09:41:16 localhost pluto[16393]: | got payload 0x800(ISAKMP_NEXT_N) needed: 0x0 opt: 0x2080
Jul  7 09:41:16 localhost pluto[16393]: | ***parse ISAKMP Notification Payload:
Jul  7 09:41:16 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:16 localhost pluto[16393]: |    length: 28
Jul  7 09:41:16 localhost pluto[16393]: |    DOI: ISAKMP_DOI_IPSEC
Jul  7 09:41:16 localhost pluto[16393]: |    protocol ID: 1
Jul  7 09:41:16 localhost pluto[16393]: |    SPI size: 16
Jul  7 09:41:16 localhost pluto[16393]: |    Notify Message Type: IPSEC_INITIAL_CONTACT
Jul  7 09:41:16 localhost pluto[16393]: "vpn-connection" #1: ignoring informational payload, type IPSEC_INITIAL_CONTACT msgid=00000000
Jul  7 09:41:16 localhost pluto[16393]: | info:  1a 43 d8 0b  81 36 b0 c3  88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: "vpn-connection" #1: Main mode peer ID is ID_IPV4_ADDR: '12.13.14.15'
Jul  7 09:41:16 localhost pluto[16393]: | hashing 48 bytes of SA
Jul  7 09:41:16 localhost pluto[16393]: | authentication succeeded
Jul  7 09:41:16 localhost pluto[16393]: | complete state transition with STF_OK
Jul  7 09:41:16 localhost pluto[16393]: "vpn-connection" #1: transition from state STATE_MAIN_I3 to state STATE_MAIN_I4
Jul  7 09:41:16 localhost pluto[16393]: | deleting event for #1
Jul  7 09:41:16 localhost pluto[16393]: | inserting event EVENT_SA_REPLACE, timeout in 3011 seconds for #1
Jul  7 09:41:16 localhost pluto[16393]: | event added after event EVENT_PENDING_PHASE2
Jul  7 09:41:16 localhost pluto[16393]: "vpn-connection" #1: STATE_MAIN_I4: ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=oakley_3des_cbc_192 prf=oakley_sha group=modp1024}
Jul  7 09:41:16 localhost pluto[16393]: | modecfg pull: noquirk policy:push not-client
Jul  7 09:41:16 localhost pluto[16393]: | phase 1 is done, looking for phase 2 to unpend
Jul  7 09:41:16 localhost pluto[16393]: | unqueuing pending Quick Mode with 12.13.14.15 "vpn-connection" import:admin initiate
Jul  7 09:41:16 localhost pluto[16393]: | duplicating state object #1
Jul  7 09:41:16 localhost pluto[16393]: | creating state object #2 at 0x8cfce68
Jul  7 09:41:16 localhost pluto[16393]: | processing connection vpn-connection
Jul  7 09:41:16 localhost pluto[16393]: | ICOOKIE:  1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:16 localhost pluto[16393]: | RCOOKIE:  88 aa 62 f5  46 d0 50 23
Jul  7 09:41:16 localhost pluto[16393]: | state hash entry 30
Jul  7 09:41:16 localhost pluto[16393]: | inserting state object #2 on chain 30
Jul  7 09:41:16 localhost pluto[16393]: | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #2
Jul  7 09:41:16 localhost pluto[16393]: | event added at head of queue
Jul  7 09:41:16 localhost pluto[16393]: | kernel_alg_esp_enc_ok(3,0): alg_id=3, alg_ivlen=8, alg_minbits=192, alg_maxbits=192, res=0, ret=1
Jul  7 09:41:16 localhost pluto[16393]: | kernel_alg_esp_enc_keylen():alg_id=3, keylen=24
Jul  7 09:41:16 localhost pluto[16393]: | kernel_alg_esp_auth_keylen(auth=2, sadb_aalg=3): a_keylen=20
Jul  7 09:41:16 localhost pluto[16393]: "vpn-connection" #2: initiating Quick Mode PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW {using isakmp#1 msgid:230da55a proposal=3DES(3)_192-SHA1(2)_160 pfsgroup=OAKLEY_GROUP_MODP1024}
Jul  7 09:41:16 localhost pluto[16393]: | 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
Jul  7 09:41:16 localhost pluto[16393]: | asking helper 0 to do build_kenonce op on seq: 3 (len=2668, pcw_work=1)
Jul  7 09:41:16 localhost pluto[16393]: | crypto helper write of request: cnt=2668<wlen=2668.  
Jul  7 09:41:16 localhost pluto[16393]: | deleting event for #2
Jul  7 09:41:16 localhost pluto[16393]: | inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #2
Jul  7 09:41:16 localhost pluto[16393]: | event added after event EVENT_PENDING_PHASE2
Jul  7 09:41:16 localhost pluto[16393]: | * processed 0 messages from cryptographic helpers 
Jul  7 09:41:16 localhost pluto[16393]: | next event EVENT_PENDING_DDNS in 36 seconds
Jul  7 09:41:16 localhost pluto[16393]: | next event EVENT_PENDING_DDNS in 36 seconds
Jul  7 09:41:17 localhost pluto[16393]: |  
Jul  7 09:41:17 localhost pluto[16393]: | helper 0 has finished work (cnt now 1)
Jul  7 09:41:17 localhost pluto[16393]: | helper 0 replies to id: q#3
Jul  7 09:41:17 localhost pluto[16393]: | calling callback function 0x80722f1
Jul  7 09:41:17 localhost pluto[16393]: | quick outI1: calculated ke+nonce, sending I1
Jul  7 09:41:17 localhost pluto[16393]: | processing connection vpn-connection
Jul  7 09:41:17 localhost pluto[16393]: | **emit ISAKMP Message:
Jul  7 09:41:17 localhost pluto[16393]: |    initiator cookie:
Jul  7 09:41:17 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:17 localhost pluto[16393]: |    responder cookie:
Jul  7 09:41:17 localhost pluto[16393]: |   88 aa 62 f5  46 d0 50 23
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_HASH
Jul  7 09:41:17 localhost pluto[16393]: |    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
Jul  7 09:41:17 localhost pluto[16393]: |    exchange type: ISAKMP_XCHG_QUICK
Jul  7 09:41:17 localhost pluto[16393]: |    flags: ISAKMP_FLAG_ENCRYPTION
Jul  7 09:41:17 localhost pluto[16393]: |    message ID:  5a a5 0d 23
Jul  7 09:41:17 localhost pluto[16393]: | ***emit ISAKMP Hash Payload:
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_SA
Jul  7 09:41:17 localhost pluto[16393]: | emitting 20 zero bytes of HASH into ISAKMP Hash Payload
Jul  7 09:41:17 localhost pluto[16393]: | emitting length of ISAKMP Hash Payload: 24
Jul  7 09:41:17 localhost pluto[16393]: | kernel_alg_db_new() initial trans_cnt=90
Jul  7 09:41:17 localhost pluto[16393]: | kernel_alg_db_new() will return p_new->protoid=3, p_new->trans_cnt=1
Jul  7 09:41:17 localhost pluto[16393]: | kernel_alg_db_new()     trans[0]: transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=2
Jul  7 09:41:17 localhost pluto[16393]: | returning new proposal from esp_info
Jul  7 09:41:17 localhost pluto[16393]: | ***emit ISAKMP Security Association Payload:
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONCE
Jul  7 09:41:17 localhost pluto[16393]: |    DOI: ISAKMP_DOI_IPSEC
Jul  7 09:41:17 localhost pluto[16393]: | ****emit IPsec DOI SIT:
Jul  7 09:41:17 localhost pluto[16393]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Jul  7 09:41:17 localhost pluto[16393]: | out_sa pcn: 0 has 1 valid proposals
Jul  7 09:41:17 localhost pluto[16393]: | out_sa pcn: 0 pn: 0<1 valid_count: 1 trans_cnt: 1
Jul  7 09:41:17 localhost pluto[16393]: | ****emit ISAKMP Proposal Payload:
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:17 localhost pluto[16393]: |    proposal number: 0
Jul  7 09:41:17 localhost pluto[16393]: |    protocol ID: PROTO_IPSEC_ESP
Jul  7 09:41:17 localhost pluto[16393]: |    SPI size: 4
Jul  7 09:41:17 localhost pluto[16393]: |    number of transforms: 1
Jul  7 09:41:17 localhost pluto[16393]: | netlink_get_spi: allocated 0x176959fd for esp.0 at 192.168.25.77
Jul  7 09:41:17 localhost pluto[16393]: | emitting 4 raw bytes of SPI into ISAKMP Proposal Payload
Jul  7 09:41:17 localhost pluto[16393]: | SPI  17 69 59 fd
Jul  7 09:41:17 localhost pluto[16393]: | *****emit ISAKMP Transform Payload (ESP):
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:17 localhost pluto[16393]: |    transform number: 0
Jul  7 09:41:17 localhost pluto[16393]: |    transform ID: ESP_3DES
Jul  7 09:41:17 localhost pluto[16393]: | ******emit ISAKMP IPsec DOI attribute:
Jul  7 09:41:17 localhost pluto[16393]: |    af+type: GROUP_DESCRIPTION
Jul  7 09:41:17 localhost pluto[16393]: |    length/value: 2
Jul  7 09:41:17 localhost pluto[16393]: |     [2 is OAKLEY_GROUP_MODP1024]
Jul  7 09:41:17 localhost pluto[16393]: | ******emit ISAKMP IPsec DOI attribute:
Jul  7 09:41:17 localhost pluto[16393]: |    af+type: ENCAPSULATION_MODE
Jul  7 09:41:17 localhost pluto[16393]: |    length/value: 1
Jul  7 09:41:17 localhost pluto[16393]: |     [1 is ENCAPSULATION_MODE_TUNNEL]
Jul  7 09:41:17 localhost pluto[16393]: | ******emit ISAKMP IPsec DOI attribute:
Jul  7 09:41:17 localhost pluto[16393]: |    af+type: SA_LIFE_TYPE
Jul  7 09:41:17 localhost pluto[16393]: |    length/value: 1
Jul  7 09:41:17 localhost pluto[16393]: |     [1 is SA_LIFE_TYPE_SECONDS]
Jul  7 09:41:17 localhost pluto[16393]: | ******emit ISAKMP IPsec DOI attribute:
Jul  7 09:41:17 localhost pluto[16393]: |    af+type: SA_LIFE_DURATION
Jul  7 09:41:17 localhost pluto[16393]: |    length/value: 28800
Jul  7 09:41:17 localhost pluto[16393]: | ******emit ISAKMP IPsec DOI attribute:
Jul  7 09:41:17 localhost pluto[16393]: |    af+type: AUTH_ALGORITHM
Jul  7 09:41:17 localhost pluto[16393]: |    length/value: 2
Jul  7 09:41:17 localhost pluto[16393]: |     [2 is AUTH_ALGORITHM_HMAC_SHA1]
Jul  7 09:41:17 localhost pluto[16393]: | emitting length of ISAKMP Transform Payload (ESP): 28
Jul  7 09:41:17 localhost pluto[16393]: | emitting length of ISAKMP Proposal Payload: 40
Jul  7 09:41:17 localhost pluto[16393]: | emitting length of ISAKMP Security Association Payload: 52
Jul  7 09:41:17 localhost pluto[16393]: | ***emit ISAKMP Nonce Payload:
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_KE
Jul  7 09:41:17 localhost pluto[16393]: | emitting 16 raw bytes of Ni into ISAKMP Nonce Payload
Jul  7 09:41:17 localhost pluto[16393]: | Ni  96 47 e6 57  cf 46 43 81  07 4d 86 df  7d 90 20 48
Jul  7 09:41:17 localhost pluto[16393]: | emitting length of ISAKMP Nonce Payload: 20
Jul  7 09:41:17 localhost pluto[16393]: | ***emit ISAKMP Key Exchange Payload:
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_ID
Jul  7 09:41:17 localhost pluto[16393]: | emitting 128 raw bytes of keyex value into ISAKMP Key Exchange Payload
Jul  7 09:41:17 localhost pluto[16393]: | keyex value  9d 48 e3 d5  fb 2a 51 f8  d7 ab fb ff  bb b1 09 61
Jul  7 09:41:17 localhost pluto[16393]: | keyex value  20 69 59 0c  09 3b 58 45  22 b6 16 5e  8d 4b fd 59
Jul  7 09:41:17 localhost pluto[16393]: | keyex value  ee d4 c9 57  8c 7d 54 96  88 46 52 0a  5b b2 43 17
Jul  7 09:41:17 localhost pluto[16393]: | keyex value  e0 40 d0 15  3e 18 4f 30  b1 31 57 21  42 d5 6a 15
Jul  7 09:41:17 localhost pluto[16393]: | keyex value  5b bf e5 ee  26 64 34 65  9d 5c 68 2b  3e 65 df ef
Jul  7 09:41:17 localhost pluto[16393]: | keyex value  fb fb 99 0d  12 d5 f5 16  93 46 ed f3  0c 10 75 f0
Jul  7 09:41:17 localhost pluto[16393]: | keyex value  c6 18 cd 45  8e 77 a8 4c  1e 24 5a 37  fa 52 26 e9
Jul  7 09:41:17 localhost pluto[16393]: | keyex value  24 37 67 79  77 a8 a7 d7  9f 28 1b 2c  96 28 fa 88
Jul  7 09:41:17 localhost pluto[16393]: | emitting length of ISAKMP Key Exchange Payload: 132
Jul  7 09:41:17 localhost pluto[16393]: | ***emit ISAKMP Identification Payload (IPsec DOI):
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_ID
Jul  7 09:41:17 localhost pluto[16393]: |    ID type: ID_IPV4_ADDR
Jul  7 09:41:17 localhost pluto[16393]: |    Protocol ID: 0
Jul  7 09:41:17 localhost pluto[16393]: |    port: 0
Jul  7 09:41:17 localhost pluto[16393]: | emitting 4 raw bytes of client network into ISAKMP Identification Payload (IPsec DOI)
Jul  7 09:41:17 localhost pluto[16393]: | client network  0a 80 02 94
Jul  7 09:41:17 localhost pluto[16393]: | emitting length of ISAKMP Identification Payload (IPsec DOI): 12
Jul  7 09:41:17 localhost pluto[16393]: | ***emit ISAKMP Identification Payload (IPsec DOI):
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:17 localhost pluto[16393]: |    ID type: ID_IPV4_ADDR
Jul  7 09:41:17 localhost pluto[16393]: |    Protocol ID: 0
Jul  7 09:41:17 localhost pluto[16393]: |    port: 0
Jul  7 09:41:17 localhost pluto[16393]: | emitting 4 raw bytes of client network into ISAKMP Identification Payload (IPsec DOI)
Jul  7 09:41:17 localhost pluto[16393]: | client network  0a 56 09 31
Jul  7 09:41:17 localhost pluto[16393]: | emitting length of ISAKMP Identification Payload (IPsec DOI): 12
Jul  7 09:41:17 localhost pluto[16393]: | HASH(1) computed:
Jul  7 09:41:17 localhost pluto[16393]: |   59 4c 47 28  1a c3 2c d5  5f 3f b0 c3  ca 14 a0 a7
Jul  7 09:41:17 localhost pluto[16393]: |   d1 d3 4b 44
Jul  7 09:41:17 localhost pluto[16393]: | last Phase 1 IV:  9c 26 ce 6a  73 a6 1a c6
Jul  7 09:41:17 localhost pluto[16393]: | current Phase 1 IV:  9c 26 ce 6a  73 a6 1a c6
Jul  7 09:41:17 localhost pluto[16393]: | computed Phase 2 IV:
Jul  7 09:41:17 localhost pluto[16393]: |   0c 14 09 fb  bb 44 3c b2  77 c1 95 16  cf be f0 b7
Jul  7 09:41:17 localhost pluto[16393]: |   9d 58 ba e9
Jul  7 09:41:17 localhost pluto[16393]: | encrypting:
Jul  7 09:41:17 localhost pluto[16393]: |   01 00 00 18  59 4c 47 28  1a c3 2c d5  5f 3f b0 c3
Jul  7 09:41:17 localhost pluto[16393]: |   ca 14 a0 a7  d1 d3 4b 44  0a 00 00 34  00 00 00 01
Jul  7 09:41:17 localhost pluto[16393]: |   00 00 00 01  00 00 00 28  00 03 04 01  17 69 59 fd
Jul  7 09:41:17 localhost pluto[16393]: |   00 00 00 1c  00 03 00 00  80 03 00 02  80 04 00 01
Jul  7 09:41:17 localhost pluto[16393]: |   80 01 00 01  80 02 70 80  80 05 00 02  04 00 00 14
Jul  7 09:41:17 localhost pluto[16393]: |   96 47 e6 57  cf 46 43 81  07 4d 86 df  7d 90 20 48
Jul  7 09:41:17 localhost pluto[16393]: |   05 00 00 84  9d 48 e3 d5  fb 2a 51 f8  d7 ab fb ff
Jul  7 09:41:17 localhost pluto[16393]: |   bb b1 09 61  20 69 59 0c  09 3b 58 45  22 b6 16 5e
Jul  7 09:41:17 localhost pluto[16393]: |   8d 4b fd 59  ee d4 c9 57  8c 7d 54 96  88 46 52 0a
Jul  7 09:41:17 localhost pluto[16393]: |   5b b2 43 17  e0 40 d0 15  3e 18 4f 30  b1 31 57 21
Jul  7 09:41:17 localhost pluto[16393]: |   42 d5 6a 15  5b bf e5 ee  26 64 34 65  9d 5c 68 2b
Jul  7 09:41:17 localhost pluto[16393]: |   3e 65 df ef  fb fb 99 0d  12 d5 f5 16  93 46 ed f3
Jul  7 09:41:17 localhost pluto[16393]: |   0c 10 75 f0  c6 18 cd 45  8e 77 a8 4c  1e 24 5a 37
Jul  7 09:41:17 localhost pluto[16393]: |   fa 52 26 e9  24 37 67 79  77 a8 a7 d7  9f 28 1b 2c
Jul  7 09:41:17 localhost pluto[16393]: |   96 28 fa 88  05 00 00 0c  01 00 00 00  0a 80 02 94
Jul  7 09:41:17 localhost pluto[16393]: |   00 00 00 0c  01 00 00 00  0a 56 09 31
Jul  7 09:41:17 localhost pluto[16393]: | IV:
Jul  7 09:41:17 localhost pluto[16393]: |   0c 14 09 fb  bb 44 3c b2  77 c1 95 16  cf be f0 b7
Jul  7 09:41:17 localhost pluto[16393]: |   9d 58 ba e9
Jul  7 09:41:17 localhost pluto[16393]: | unpadded size is: 252
Jul  7 09:41:17 localhost pluto[16393]: | emitting 4 zero bytes of encryption padding into ISAKMP Message
Jul  7 09:41:17 localhost pluto[16393]: | encrypting 256 using OAKLEY_3DES_CBC
Jul  7 09:41:17 localhost pluto[16393]: | next IV:  81 b4 7d 00  87 29 5f 96
Jul  7 09:41:17 localhost pluto[16393]: | emitting length of ISAKMP Message: 284
Jul  7 09:41:17 localhost pluto[16393]: | sending 284 bytes for quick_outI1 through eth0:500 to 12.13.14.15:500 (using #2)
Jul  7 09:41:17 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3  88 aa 62 f5  46 d0 50 23
Jul  7 09:41:17 localhost pluto[16393]: |   08 10 20 01  5a a5 0d 23  00 00 01 1c  8b 4d b1 3f
Jul  7 09:41:17 localhost pluto[16393]: |   69 7e ca c0  25 e9 82 cb  4b 81 b0 ad  56 f4 e3 45
Jul  7 09:41:17 localhost pluto[16393]: |   ba 8f 17 73  f9 d1 80 5c  46 9d 21 5a  8a 95 ee b0
Jul  7 09:41:17 localhost pluto[16393]: |   12 59 00 46  cf e1 8a 34  d8 7b 35 8d  1a 46 a7 d1
Jul  7 09:41:17 localhost pluto[16393]: |   7e b1 de fd  7b dd 75 9c  42 44 7b ab  f4 bd 9e 2e
Jul  7 09:41:17 localhost pluto[16393]: |   83 1d 7c 9e  bf e9 c8 0e  63 37 72 d3  3c 15 43 4f
Jul  7 09:41:17 localhost pluto[16393]: |   f8 83 d8 38  d7 f0 1e 82  68 75 d6 ff  f8 80 2f 8b
Jul  7 09:41:17 localhost pluto[16393]: |   aa 80 b7 fd  9b 32 33 e4  29 a2 ff f4  92 3b 58 3c
Jul  7 09:41:17 localhost pluto[16393]: |   6d 01 7e 79  20 84 81 95  10 1e 74 4e  67 92 e4 dd
Jul  7 09:41:17 localhost pluto[16393]: |   b3 7c a9 38  14 37 62 9c  0c db 3a 44  67 9e fe 5a
Jul  7 09:41:17 localhost pluto[16393]: |   ee b2 3f d3  e5 2c 75 c4  96 89 45 9d  49 b7 b9 44
Jul  7 09:41:17 localhost pluto[16393]: |   c8 f1 47 97  98 0f d3 46  ae f7 6e 7b  a8 5e 7d 87
Jul  7 09:41:17 localhost pluto[16393]: |   5a f0 e3 a5  3b 17 2b c8  5f 86 86 77  bf f3 ea ee
Jul  7 09:41:17 localhost pluto[16393]: |   20 eb 2e 5b  aa 4a c4 87  e1 bb 7c 34  e7 8e 92 6c
Jul  7 09:41:17 localhost pluto[16393]: |   39 d9 d4 03  fb d9 5e 61  5c 2f 93 a5  c0 d8 fc 38
Jul  7 09:41:17 localhost pluto[16393]: |   e5 92 b4 c3  ad 64 a0 dd  52 cd d1 cd  12 4d bf 51
Jul  7 09:41:17 localhost pluto[16393]: |   ee 4d 5a 3b  81 b4 7d 00  87 29 5f 96
Jul  7 09:41:17 localhost pluto[16393]: | deleting event for #2
Jul  7 09:41:17 localhost pluto[16393]: | inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #2
Jul  7 09:41:17 localhost pluto[16393]: | event added at head of queue
Jul  7 09:41:17 localhost pluto[16393]: | * processed 1 messages from cryptographic helpers 
Jul  7 09:41:17 localhost pluto[16393]: | next event EVENT_RETRANSMIT in 10 seconds for #2
Jul  7 09:41:17 localhost pluto[16393]: | next event EVENT_RETRANSMIT in 10 seconds for #2
Jul  7 09:41:17 localhost pluto[16393]: |  
Jul  7 09:41:17 localhost pluto[16393]: | *received 284 bytes from 12.13.14.15:500 on eth0 (port=500)
Jul  7 09:41:17 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3  88 aa 62 f5  46 d0 50 23
Jul  7 09:41:17 localhost pluto[16393]: |   08 10 20 01  5a a5 0d 23  00 00 01 1c  d2 96 f7 be
Jul  7 09:41:17 localhost pluto[16393]: |   3d 70 de 1d  15 bb ed 45  9d 54 80 b8  5e a5 43 19
Jul  7 09:41:17 localhost pluto[16393]: |   b8 02 4f 68  8c 93 85 11  6b d2 8e 91  df 6b bc 15
Jul  7 09:41:17 localhost pluto[16393]: |   1a 7f 38 4e  b1 49 e3 86  77 a1 99 24  25 1a 92 30
Jul  7 09:41:17 localhost pluto[16393]: |   1b 9a 09 ab  20 49 7c 16  c5 47 5b 74  5a 79 a7 b1
Jul  7 09:41:17 localhost pluto[16393]: |   fe 32 41 2b  03 63 5b 3d  94 71 fc fa  48 e3 62 17
Jul  7 09:41:17 localhost pluto[16393]: |   e7 75 87 cd  36 78 6d 1e  b8 d5 f3 dc  55 94 6f 35
Jul  7 09:41:17 localhost pluto[16393]: |   d1 38 35 7a  e6 21 32 d8  af 81 21 6b  3b 91 32 fc
Jul  7 09:41:17 localhost pluto[16393]: |   d8 fb 2b 53  41 e9 3c a0  1f e6 76 1e  ab 37 b0 9c
Jul  7 09:41:17 localhost pluto[16393]: |   d8 7f e3 5a  78 8f 3b c5  67 e1 67 43  cc 80 17 d6
Jul  7 09:41:17 localhost pluto[16393]: |   a2 e6 6d e3  50 95 50 05  af c1 6b e0  3f df b7 ad
Jul  7 09:41:17 localhost pluto[16393]: |   0b 6f e5 05  10 e7 be c5  53 8b ca d6  1d 92 57 78
Jul  7 09:41:17 localhost pluto[16393]: |   33 d7 c6 42  87 c8 45 96  12 b0 ea ae  fa 57 28 50
Jul  7 09:41:17 localhost pluto[16393]: |   89 61 55 5c  cb 45 22 47  b1 60 dc 6b  ad a5 56 89
Jul  7 09:41:17 localhost pluto[16393]: |   c4 08 f6 12  43 14 ca 4f  93 67 79 19  c6 27 a7 42
Jul  7 09:41:17 localhost pluto[16393]: |   e4 75 8c 03  5f 1b e8 32  c4 11 a9 d6  55 69 6b d1
Jul  7 09:41:17 localhost pluto[16393]: |   2b 20 e8 9d  4c f3 bc 44  f9 37 40 98
Jul  7 09:41:17 localhost pluto[16393]: | **parse ISAKMP Message:
Jul  7 09:41:17 localhost pluto[16393]: |    initiator cookie:
Jul  7 09:41:17 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:17 localhost pluto[16393]: |    responder cookie:
Jul  7 09:41:17 localhost pluto[16393]: |   88 aa 62 f5  46 d0 50 23
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_HASH
Jul  7 09:41:17 localhost pluto[16393]: |    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
Jul  7 09:41:17 localhost pluto[16393]: |    exchange type: ISAKMP_XCHG_QUICK
Jul  7 09:41:17 localhost pluto[16393]: |    flags: ISAKMP_FLAG_ENCRYPTION
Jul  7 09:41:17 localhost pluto[16393]: |    message ID:  5a a5 0d 23
Jul  7 09:41:17 localhost pluto[16393]: |    length: 284
Jul  7 09:41:17 localhost pluto[16393]: |  processing version=1.0 packet with exchange type=ISAKMP_XCHG_QUICK (32)
Jul  7 09:41:17 localhost pluto[16393]: | ICOOKIE:  1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:17 localhost pluto[16393]: | RCOOKIE:  88 aa 62 f5  46 d0 50 23
Jul  7 09:41:17 localhost pluto[16393]: | state hash entry 30
Jul  7 09:41:17 localhost pluto[16393]: | v1 peer and cookies match on #2, provided msgid 5aa50d23 vs 5aa50d23
Jul  7 09:41:17 localhost pluto[16393]: | v1 state object #2 found, in STATE_QUICK_I1
Jul  7 09:41:17 localhost pluto[16393]: | processing connection vpn-connection
Jul  7 09:41:17 localhost pluto[16393]: | received encrypted packet from 12.13.14.15:500
Jul  7 09:41:17 localhost pluto[16393]: | decrypting 256 bytes using algorithm OAKLEY_3DES_CBC
Jul  7 09:41:17 localhost pluto[16393]: | decrypted:
Jul  7 09:41:17 localhost pluto[16393]: |   01 00 00 18  4b f2 0e fe  46 af e3 da  94 da ed 03
Jul  7 09:41:17 localhost pluto[16393]: |   50 98 aa 03  15 18 7b 5a  0a 00 00 34  00 00 00 01
Jul  7 09:41:17 localhost pluto[16393]: |   00 00 00 01  00 00 00 28  00 03 04 01  5c f5 4f e1
Jul  7 09:41:17 localhost pluto[16393]: |   00 00 00 1c  00 03 00 00  80 03 00 02  80 04 00 01
Jul  7 09:41:17 localhost pluto[16393]: |   80 01 00 01  80 02 70 80  80 05 00 02  04 00 00 18
Jul  7 09:41:17 localhost pluto[16393]: |   7b 40 4d cd  da 2c 4a 21  1a a0 57 a5  90 eb 44 10
Jul  7 09:41:17 localhost pluto[16393]: |   39 ca 92 a6  05 00 00 84  6b 3a ec bb  5d 4c 81 14
Jul  7 09:41:17 localhost pluto[16393]: |   57 9e 45 b3  41 1b 64 1f  40 03 b0 2a  2a 4d 30 9c
Jul  7 09:41:17 localhost pluto[16393]: |   07 ae 10 a1  cf e0 df ac  6d f2 64 7b  df 72 af 18
Jul  7 09:41:17 localhost pluto[16393]: |   07 50 11 80  42 e7 fa 37  42 17 eb 40  b4 bb 67 b1
Jul  7 09:41:17 localhost pluto[16393]: |   da 44 ba 50  ff b5 e6 e3  21 18 90 9d  62 dc 1d 1f
Jul  7 09:41:17 localhost pluto[16393]: |   51 be 57 e7  ea 1a f7 44  fe 29 6f be  29 7a 58 5e
Jul  7 09:41:17 localhost pluto[16393]: |   8b e8 81 f4  69 dc d1 ec  42 5a 4e 61  44 88 92 ec
Jul  7 09:41:17 localhost pluto[16393]: |   ce fc 88 f6  fa 7f 4d 70  b0 f9 85 30  14 90 8e f7
Jul  7 09:41:17 localhost pluto[16393]: |   86 9e 17 1d  20 92 9b dd  05 00 00 0c  01 00 00 00
Jul  7 09:41:17 localhost pluto[16393]: |   0a 80 02 94  00 00 00 0c  01 00 00 00  0a 56 09 31
Jul  7 09:41:17 localhost pluto[16393]: | next IV:  4c f3 bc 44  f9 37 40 98
Jul  7 09:41:17 localhost pluto[16393]: | got payload 0x100(ISAKMP_NEXT_HASH) needed: 0x502 opt: 0x200030
Jul  7 09:41:17 localhost pluto[16393]: | ***parse ISAKMP Hash Payload:
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_SA
Jul  7 09:41:17 localhost pluto[16393]: |    length: 24
Jul  7 09:41:17 localhost pluto[16393]: | got payload 0x2(ISAKMP_NEXT_SA) needed: 0x402 opt: 0x200030
Jul  7 09:41:17 localhost pluto[16393]: | ***parse ISAKMP Security Association Payload:
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONCE
Jul  7 09:41:17 localhost pluto[16393]: |    length: 52
Jul  7 09:41:17 localhost pluto[16393]: |    DOI: ISAKMP_DOI_IPSEC
Jul  7 09:41:17 localhost pluto[16393]: | got payload 0x400(ISAKMP_NEXT_NONCE) needed: 0x400 opt: 0x200030
Jul  7 09:41:17 localhost pluto[16393]: | ***parse ISAKMP Nonce Payload:
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_KE
Jul  7 09:41:17 localhost pluto[16393]: |    length: 24
Jul  7 09:41:17 localhost pluto[16393]: | got payload 0x10(ISAKMP_NEXT_KE) needed: 0x0 opt: 0x200030
Jul  7 09:41:17 localhost pluto[16393]: | ***parse ISAKMP Key Exchange Payload:
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_ID
Jul  7 09:41:17 localhost pluto[16393]: |    length: 132
Jul  7 09:41:17 localhost pluto[16393]: | got payload 0x20(ISAKMP_NEXT_ID) needed: 0x0 opt: 0x200030
Jul  7 09:41:17 localhost pluto[16393]: | ***parse ISAKMP Identification Payload (IPsec DOI):
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_ID
Jul  7 09:41:17 localhost pluto[16393]: |    length: 12
Jul  7 09:41:17 localhost pluto[16393]: |    ID type: ID_IPV4_ADDR
Jul  7 09:41:17 localhost pluto[16393]: |    Protocol ID: 0
Jul  7 09:41:17 localhost pluto[16393]: |    port: 0
Jul  7 09:41:17 localhost pluto[16393]: |      obj:   0a 80 02 94  00 00 00 0c  01 00 00 00
Jul  7 09:41:17 localhost pluto[16393]: | got payload 0x20(ISAKMP_NEXT_ID) needed: 0x0 opt: 0x200030
Jul  7 09:41:17 localhost pluto[16393]: | ***parse ISAKMP Identification Payload (IPsec DOI):
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:17 localhost pluto[16393]: |    length: 12
Jul  7 09:41:17 localhost pluto[16393]: |    ID type: ID_IPV4_ADDR
Jul  7 09:41:17 localhost pluto[16393]: |    Protocol ID: 0
Jul  7 09:41:17 localhost pluto[16393]: |    port: 0
Jul  7 09:41:17 localhost pluto[16393]: |      obj:   0a 56 09 31  21 01 00 00  1a 43 d8 0b
Jul  7 09:41:17 localhost pluto[16393]: | **emit ISAKMP Message:
Jul  7 09:41:17 localhost pluto[16393]: |    initiator cookie:
Jul  7 09:41:17 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3
Jul  7 09:41:17 localhost pluto[16393]: |    responder cookie:
Jul  7 09:41:17 localhost pluto[16393]: |   88 aa 62 f5  46 d0 50 23
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_HASH
Jul  7 09:41:17 localhost pluto[16393]: |    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
Jul  7 09:41:17 localhost pluto[16393]: |    exchange type: ISAKMP_XCHG_QUICK
Jul  7 09:41:17 localhost pluto[16393]: |    flags: ISAKMP_FLAG_ENCRYPTION
Jul  7 09:41:17 localhost pluto[16393]: |    message ID:  5a a5 0d 23
Jul  7 09:41:17 localhost pluto[16393]: | HASH(2) computed:
Jul  7 09:41:17 localhost pluto[16393]: |   4b f2 0e fe  46 af e3 da  94 da ed 03  50 98 aa 03
Jul  7 09:41:17 localhost pluto[16393]: |   15 18 7b 5a
Jul  7 09:41:17 localhost pluto[16393]: | ****parse IPsec DOI SIT:
Jul  7 09:41:17 localhost pluto[16393]: |    IPsec DOI SIT: SIT_IDENTITY_ONLY
Jul  7 09:41:17 localhost pluto[16393]: | ****parse ISAKMP Proposal Payload:
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:17 localhost pluto[16393]: |    length: 40
Jul  7 09:41:17 localhost pluto[16393]: |    proposal number: 0
Jul  7 09:41:17 localhost pluto[16393]: |    protocol ID: PROTO_IPSEC_ESP
Jul  7 09:41:17 localhost pluto[16393]: |    SPI size: 4
Jul  7 09:41:17 localhost pluto[16393]: |    number of transforms: 1
Jul  7 09:41:17 localhost pluto[16393]: | parsing 4 raw bytes of ISAKMP Proposal Payload into SPI
Jul  7 09:41:17 localhost pluto[16393]: | SPI  5c f5 4f e1
Jul  7 09:41:17 localhost pluto[16393]: | *****parse ISAKMP Transform Payload (ESP):
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:17 localhost pluto[16393]: |    length: 28
Jul  7 09:41:17 localhost pluto[16393]: |    transform number: 0
Jul  7 09:41:17 localhost pluto[16393]: |    transform ID: ESP_3DES
Jul  7 09:41:17 localhost pluto[16393]: | ******parse ISAKMP IPsec DOI attribute:
Jul  7 09:41:17 localhost pluto[16393]: |    af+type: GROUP_DESCRIPTION
Jul  7 09:41:17 localhost pluto[16393]: |    length/value: 2
Jul  7 09:41:17 localhost pluto[16393]: |    [2 is OAKLEY_GROUP_MODP1024]
Jul  7 09:41:17 localhost pluto[16393]: | ******parse ISAKMP IPsec DOI attribute:
Jul  7 09:41:17 localhost pluto[16393]: |    af+type: ENCAPSULATION_MODE
Jul  7 09:41:17 localhost pluto[16393]: |    length/value: 1
Jul  7 09:41:17 localhost pluto[16393]: |    [1 is ENCAPSULATION_MODE_TUNNEL]
Jul  7 09:41:17 localhost pluto[16393]: | ******parse ISAKMP IPsec DOI attribute:
Jul  7 09:41:17 localhost pluto[16393]: |    af+type: SA_LIFE_TYPE
Jul  7 09:41:17 localhost pluto[16393]: |    length/value: 1
Jul  7 09:41:17 localhost pluto[16393]: |    [1 is SA_LIFE_TYPE_SECONDS]
Jul  7 09:41:17 localhost pluto[16393]: | ******parse ISAKMP IPsec DOI attribute:
Jul  7 09:41:17 localhost pluto[16393]: |    af+type: SA_LIFE_DURATION
Jul  7 09:41:17 localhost pluto[16393]: |    length/value: 28800
Jul  7 09:41:17 localhost pluto[16393]: | ******parse ISAKMP IPsec DOI attribute:
Jul  7 09:41:17 localhost pluto[16393]: |    af+type: AUTH_ALGORITHM
Jul  7 09:41:17 localhost pluto[16393]: |    length/value: 2
Jul  7 09:41:17 localhost pluto[16393]: |    [2 is AUTH_ALGORITHM_HMAC_SHA1]
Jul  7 09:41:17 localhost pluto[16393]: | kernel_alg_esp_enc_ok(3,0): alg_id=3, alg_ivlen=8, alg_minbits=192, alg_maxbits=192, res=0, ret=1
Jul  7 09:41:17 localhost pluto[16393]: | kernel_alg_esp_enc_keylen():alg_id=3, keylen=24
Jul  7 09:41:17 localhost pluto[16393]: | DH public value received:
Jul  7 09:41:17 localhost pluto[16393]: |   6b 3a ec bb  5d 4c 81 14  57 9e 45 b3  41 1b 64 1f
Jul  7 09:41:17 localhost pluto[16393]: |   40 03 b0 2a  2a 4d 30 9c  07 ae 10 a1  cf e0 df ac
Jul  7 09:41:17 localhost pluto[16393]: |   6d f2 64 7b  df 72 af 18  07 50 11 80  42 e7 fa 37
Jul  7 09:41:17 localhost pluto[16393]: |   42 17 eb 40  b4 bb 67 b1  da 44 ba 50  ff b5 e6 e3
Jul  7 09:41:17 localhost pluto[16393]: |   21 18 90 9d  62 dc 1d 1f  51 be 57 e7  ea 1a f7 44
Jul  7 09:41:17 localhost pluto[16393]: |   fe 29 6f be  29 7a 58 5e  8b e8 81 f4  69 dc d1 ec
Jul  7 09:41:17 localhost pluto[16393]: |   42 5a 4e 61  44 88 92 ec  ce fc 88 f6  fa 7f 4d 70
Jul  7 09:41:17 localhost pluto[16393]: |   b0 f9 85 30  14 90 8e f7  86 9e 17 1d  20 92 9b dd
Jul  7 09:41:17 localhost pluto[16393]: | started looking for secret for 192.168.25.77->12.13.14.15 of kind PPK_PSK
Jul  7 09:41:17 localhost pluto[16393]: | actually looking for secret for 192.168.25.77->12.13.14.15 of kind PPK_PSK
Jul  7 09:41:17 localhost pluto[16393]: | line 19: key type PPK_PSK(192.168.25.77) to type PPK_PSK 
Jul  7 09:41:17 localhost pluto[16393]: | 1: compared key 12.13.14.15 to 192.168.25.77 / 12.13.14.15 -> 4
Jul  7 09:41:17 localhost pluto[16393]: | 2: compared key 192.168.25.77 to 192.168.25.77 / 12.13.14.15 -> 12
Jul  7 09:41:17 localhost pluto[16393]: | line 19: match=12 
Jul  7 09:41:17 localhost pluto[16393]: | best_match 0>12 best=0x8cfb4a8 (line=19)
Jul  7 09:41:17 localhost pluto[16393]: | line 17: key type PPK_PSK(192.168.25.77) to type PPK_PSK 
Jul  7 09:41:17 localhost pluto[16393]: | 1: compared key 12.13.14.15 to 192.168.25.77 / 12.13.14.15 -> 4
Jul  7 09:41:17 localhost pluto[16393]: | 2: compared key "my local static ip" to 192.168.25.77 / 12.13.14.15 -> 4
Jul  7 09:41:17 localhost pluto[16393]: | line 17: match=4 
Jul  7 09:41:17 localhost pluto[16393]: | line 1: key type PPK_PSK(192.168.25.77) to type PPK_RSA 
Jul  7 09:41:17 localhost pluto[16393]: | concluding with best_match=12 best=0x8cfb4a8 (lineno=19)
Jul  7 09:41:17 localhost pluto[16393]: | 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
Jul  7 09:41:17 localhost pluto[16393]: | asking helper 0 to do compute dh(p2) op on seq: 4 (len=2668, pcw_work=1)
Jul  7 09:41:17 localhost pluto[16393]: | crypto helper write of request: cnt=2668<wlen=2668.  
Jul  7 09:41:17 localhost pluto[16393]: | deleting event for #2
Jul  7 09:41:17 localhost pluto[16393]: | inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #2
Jul  7 09:41:17 localhost pluto[16393]: | event added after event EVENT_PENDING_PHASE2
Jul  7 09:41:17 localhost pluto[16393]: | complete state transition with STF_SUSPEND
Jul  7 09:41:17 localhost pluto[16393]: | * processed 0 messages from cryptographic helpers 
Jul  7 09:41:17 localhost pluto[16393]: | next event EVENT_PENDING_DDNS in 35 seconds
Jul  7 09:41:17 localhost pluto[16393]: | next event EVENT_PENDING_DDNS in 35 seconds
Jul  7 09:41:17 localhost pluto[16393]: |  
Jul  7 09:41:17 localhost pluto[16393]: | helper 0 has finished work (cnt now 1)
Jul  7 09:41:17 localhost pluto[16393]: | helper 0 replies to id: q#4
Jul  7 09:41:17 localhost pluto[16393]: | calling callback function 0x8075dee
Jul  7 09:41:17 localhost pluto[16393]: | quick inI1_outR1: calculated ke+nonce, calculating DH
Jul  7 09:41:17 localhost pluto[16393]: | processing connection vpn-connection
Jul  7 09:41:17 localhost pluto[16393]: | our client is 192.168.25.77
Jul  7 09:41:17 localhost pluto[16393]: | our client protocol/port is 0/0
Jul  7 09:41:17 localhost pluto[16393]: | peer client is 192.168.66.77
Jul  7 09:41:17 localhost pluto[16393]: | peer client protocol/port is 0/0
Jul  7 09:41:17 localhost pluto[16393]: | ***emit ISAKMP Hash Payload:
Jul  7 09:41:17 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:41:17 localhost pluto[16393]: | emitting 20 zero bytes of HASH into ISAKMP Hash Payload
Jul  7 09:41:17 localhost pluto[16393]: | emitting length of ISAKMP Hash Payload: 24
Jul  7 09:41:17 localhost pluto[16393]: | HASH(3) computed:  11 91 82 95  27 37 f0 4c  7d 17 6c ad  8e 00 4a 74
Jul  7 09:41:17 localhost pluto[16393]: | HASH(3) computed:  94 49 b0 73
Jul  7 09:41:17 localhost pluto[16393]: | compute_proto_keymat:needed_len (after ESP enc)=24
Jul  7 09:41:17 localhost pluto[16393]: | compute_proto_keymat:needed_len (after ESP auth)=44
Jul  7 09:41:17 localhost pluto[16393]: | ESP KEYMAT 
Jul  7 09:41:17 localhost pluto[16393]: |   KEYMAT computed:
Jul  7 09:41:17 localhost pluto[16393]: |   54 30 7c be  f5 9f 43 74  82 53 46 43  24 e1 dc 9b
Jul  7 09:41:17 localhost pluto[16393]: |   7a 0f da e1  be 3c ef 45  1b 59 1c 33  db 8f e5 ba
Jul  7 09:41:17 localhost pluto[16393]: |   b7 07 26 91  c6 8c c2 0c  f1 c8 07 6b
Jul  7 09:41:17 localhost pluto[16393]: |   Peer KEYMAT computed:
Jul  7 09:41:17 localhost pluto[16393]: |   c3 d1 f1 43  0e cd 90 e2  da ce 76 2a  89 2f 05 17
Jul  7 09:41:17 localhost pluto[16393]: |   14 08 6a 5d  96 38 78 a0  c4 07 21 84  71 41 59 61
Jul  7 09:41:17 localhost pluto[16393]: |   24 4c 10 8a  14 b2 3f 9d  1e fb 60 1b
Jul  7 09:41:17 localhost pluto[16393]: | install_ipsec_sa() for #2: inbound and outbound
Jul  7 09:41:17 localhost pluto[16393]: | route owner of "vpn-connection" unrouted: NULL; eroute owner: NULL
Jul  7 09:41:17 localhost pluto[16393]: | could_route called for vpn-connection (kind=CK_PERMANENT)
Jul  7 09:41:17 localhost pluto[16393]: | looking for alg with transid: 3 keylen: 0 auth: 2 
Jul  7 09:41:17 localhost pluto[16393]: | checking transid: 11 keylen: 0 auth: 1 
Jul  7 09:41:17 localhost pluto[16393]: | checking transid: 11 keylen: 0 auth: 2 
Jul  7 09:41:17 localhost pluto[16393]: | checking transid: 2 keylen: 8 auth: 0 
Jul  7 09:41:17 localhost pluto[16393]: | checking transid: 2 keylen: 8 auth: 1 
Jul  7 09:41:17 localhost pluto[16393]: | checking transid: 2 keylen: 8 auth: 2 
Jul  7 09:41:17 localhost pluto[16393]: | checking transid: 3 keylen: 24 auth: 0 
Jul  7 09:41:17 localhost pluto[16393]: | checking transid: 3 keylen: 24 auth: 1 
Jul  7 09:41:17 localhost pluto[16393]: | checking transid: 3 keylen: 24 auth: 2 
Jul  7 09:41:17 localhost pluto[16393]: | esp enckey:  c3 d1 f1 43  0e cd 90 e2  da ce 76 2a  89 2f 05 17
Jul  7 09:41:17 localhost pluto[16393]: | esp enckey:  14 08 6a 5d  96 38 78 a0
Jul  7 09:41:17 localhost pluto[16393]: | esp authkey:  c4 07 21 84  71 41 59 61  24 4c 10 8a  14 b2 3f 9d
Jul  7 09:41:17 localhost pluto[16393]: | esp authkey:  1e fb 60 1b
Jul  7 09:41:17 localhost pluto[16393]: | set up outoing SA, ref=0/4294901761
Jul  7 09:41:17 localhost pluto[16393]: | looking for alg with transid: 3 keylen: 0 auth: 2 
Jul  7 09:41:17 localhost pluto[16393]: | checking transid: 11 keylen: 0 auth: 1 
Jul  7 09:41:17 localhost pluto[16393]: | checking transid: 11 keylen: 0 auth: 2 
Jul  7 09:41:17 localhost pluto[16393]: | checking transid: 2 keylen: 8 auth: 0 
Jul  7 09:41:17 localhost pluto[16393]: | checking transid: 2 keylen: 8 auth: 1 
Jul  7 09:41:17 localhost pluto[16393]: | checking transid: 2 keylen: 8 auth: 2 
Jul  7 09:41:17 localhost pluto[16393]: | checking transid: 3 keylen: 24 auth: 0 
Jul  7 09:41:17 localhost pluto[16393]: | checking transid: 3 keylen: 24 auth: 1 
Jul  7 09:41:17 localhost pluto[16393]: | checking transid: 3 keylen: 24 auth: 2 
Jul  7 09:41:17 localhost pluto[16393]: | esp enckey:  54 30 7c be  f5 9f 43 74  82 53 46 43  24 e1 dc 9b
Jul  7 09:41:17 localhost pluto[16393]: | esp enckey:  7a 0f da e1  be 3c ef 45
Jul  7 09:41:17 localhost pluto[16393]: | esp authkey:  1b 59 1c 33  db 8f e5 ba  b7 07 26 91  c6 8c c2 0c
Jul  7 09:41:17 localhost pluto[16393]: | esp authkey:  f1 c8 07 6b
Jul  7 09:41:17 localhost pluto[16393]: | add inbound eroute 192.168.66.77/32:0 --0-> 192.168.25.77/32:0 => tun.10000 at 192.168.25.77 (raw_eroute)
Jul  7 09:41:17 localhost pluto[16393]: | raw_eroute result=1 
Jul  7 09:41:17 localhost pluto[16393]: | set up incoming SA, ref=0/4294901761
Jul  7 09:41:17 localhost pluto[16393]: | sr for #2: unrouted
Jul  7 09:41:17 localhost pluto[16393]: | route owner of "vpn-connection" unrouted: NULL; eroute owner: NULL
Jul  7 09:41:17 localhost pluto[16393]: | route_and_eroute with c: vpn-connection (next: none) ero:null esr:{(nil)} ro:null rosr:{(nil)} and state: 2
Jul  7 09:41:17 localhost pluto[16393]: | eroute_connection add eroute 192.168.25.77/32:0 --0-> 192.168.66.77/32:0 => tun.0 at 12.13.14.15 (raw_eroute)
Jul  7 09:41:17 localhost pluto[16393]: | raw_eroute result=1 
Jul  7 09:41:17 localhost pluto[16393]: | command executing up-host
Jul  7 09:41:17 localhost pluto[16393]: | executing up-host: 2>&1 PLUTO_VERB='up-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='vpn-connection' PLUTO_INTERFACE='eth0' PLUTO_NEXT_HOP='12.13.14.15' PLUTO_ME='192.168.25.77' PLUTO_MY_ID='192.168.25.77' PLUTO_MY_CLIENT='192.168.25.77/32' PLUTO_MY_CLIENT_NET='192.168.25.77' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='12.13.14.15' PLUTO_PEER_ID='12.13.14.15' PLUTO_PEER_CLIENT='192.168.66.77/32' PLUTO_PEER_CLIENT_NET='192.168.66.77' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW' PLUTO_XAUTH_USERNAME=''  ipsec _updown
Jul  7 09:41:17 localhost pluto[16393]: | popen(): cmd is 676 chars long
Jul  7 09:41:17 localhost pluto[16393]: | cmd(   0):2>&1 PLUTO_VERB='up-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='vpn-connection' PL:
Jul  7 09:41:17 localhost pluto[16393]: | cmd(  80):UTO_INTERFACE='eth0' PLUTO_NEXT_HOP='12.13.14.15' PLUTO_ME='192.168.25.77' PLUT:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 160):O_MY_ID='192.168.25.77' PLUTO_MY_CLIENT='192.168.25.77/32' PLUTO_MY_CLIENT_NET='10:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 240):.128.2.148' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PR:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 320):OTOCOL='0' PLUTO_PEER='12.13.14.15' PLUTO_PEER_ID='12.13.14.15' PLUTO_PEER_C:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 400):LIENT='192.168.66.77/32' PLUTO_PEER_CLIENT_NET='192.168.66.77' PLUTO_PEER_CLIENT_MASK=:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 480):'255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' P:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 560):LUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW' PL:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 640):UTO_XAUTH_USERNAME=''  ipsec _updown:
Jul  7 09:41:17 localhost pluto[16393]: | route_and_eroute: firewall_notified: true
Jul  7 09:41:17 localhost pluto[16393]: | command executing prepare-host
Jul  7 09:41:17 localhost pluto[16393]: | executing prepare-host: 2>&1 PLUTO_VERB='prepare-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='vpn-connection' PLUTO_INTERFACE='eth0' PLUTO_NEXT_HOP='12.13.14.15' PLUTO_ME='192.168.25.77' PLUTO_MY_ID='192.168.25.77' PLUTO_MY_CLIENT='192.168.25.77/32' PLUTO_MY_CLIENT_NET='192.168.25.77' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='12.13.14.15' PLUTO_PEER_ID='12.13.14.15' PLUTO_PEER_CLIENT='192.168.66.77/32' PLUTO_PEER_CLIENT_NET='192.168.66.77' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW' PLUTO_XAUTH_USERNAME=''  ipsec _updown
Jul  7 09:41:17 localhost pluto[16393]: | popen(): cmd is 681 chars long
Jul  7 09:41:17 localhost pluto[16393]: | cmd(   0):2>&1 PLUTO_VERB='prepare-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='vpn-redwork:
Jul  7 09:41:17 localhost pluto[16393]: | cmd(  80):s' PLUTO_INTERFACE='eth0' PLUTO_NEXT_HOP='12.13.14.15' PLUTO_ME='192.168.25.77':
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 160): PLUTO_MY_ID='192.168.25.77' PLUTO_MY_CLIENT='192.168.25.77/32' PLUTO_MY_CLIENT_NE:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 240):T='192.168.25.77' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 320):MY_PROTOCOL='0' PLUTO_PEER='12.13.14.15' PLUTO_PEER_ID='12.13.14.15' PLUTO_P:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 400):EER_CLIENT='192.168.66.77/32' PLUTO_PEER_CLIENT_NET='192.168.66.77' PLUTO_PEER_CLIENT_:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 480):MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 560):='' PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLO:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 640):W' PLUTO_XAUTH_USERNAME=''  ipsec _updown:
Jul  7 09:41:17 localhost pluto[16393]: | command executing route-host
Jul  7 09:41:17 localhost pluto[16393]: | executing route-host: 2>&1 PLUTO_VERB='route-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='vpn-connection' PLUTO_INTERFACE='eth0' PLUTO_NEXT_HOP='12.13.14.15' PLUTO_ME='192.168.25.77' PLUTO_MY_ID='192.168.25.77' PLUTO_MY_CLIENT='192.168.25.77/32' PLUTO_MY_CLIENT_NET='192.168.25.77' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='12.13.14.15' PLUTO_PEER_ID='12.13.14.15' PLUTO_PEER_CLIENT='192.168.66.77/32' PLUTO_PEER_CLIENT_NET='192.168.66.77' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW' PLUTO_XAUTH_USERNAME=''  ipsec _updown
Jul  7 09:41:17 localhost pluto[16393]: | popen(): cmd is 679 chars long
Jul  7 09:41:17 localhost pluto[16393]: | cmd(   0):2>&1 PLUTO_VERB='route-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='vpn-connection':
Jul  7 09:41:17 localhost pluto[16393]: | cmd(  80): PLUTO_INTERFACE='eth0' PLUTO_NEXT_HOP='12.13.14.15' PLUTO_ME='192.168.25.77' P:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 160):LUTO_MY_ID='192.168.25.77' PLUTO_MY_CLIENT='192.168.25.77/32' PLUTO_MY_CLIENT_NET=:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 240):'192.168.25.77' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 320):_PROTOCOL='0' PLUTO_PEER='12.13.14.15' PLUTO_PEER_ID='12.13.14.15' PLUTO_PEE:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 400):R_CLIENT='192.168.66.77/32' PLUTO_PEER_CLIENT_NET='192.168.66.77' PLUTO_PEER_CLIENT_MA:
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 480):SK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA=':
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 560):' PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW':
Jul  7 09:41:17 localhost pluto[16393]: | cmd( 640): PLUTO_XAUTH_USERNAME=''  ipsec _updown:
Jul  7 09:41:17 localhost pluto[16393]: | route_and_eroute: instance "vpn-connection", setting eroute_owner {spd=0x8cf94b0,sr=0x8cf94b0} to #2 (was #0) (newest_ipsec_sa=#0)
Jul  7 09:41:17 localhost pluto[16393]: | encrypting:
Jul  7 09:41:17 localhost pluto[16393]: |   00 00 00 18  11 91 82 95  27 37 f0 4c  7d 17 6c ad
Jul  7 09:41:17 localhost pluto[16393]: |   8e 00 4a 74  94 49 b0 73
Jul  7 09:41:17 localhost pluto[16393]: | IV:
Jul  7 09:41:17 localhost pluto[16393]: |   4c f3 bc 44  f9 37 40 98
Jul  7 09:41:17 localhost pluto[16393]: | unpadded size is: 24
Jul  7 09:41:17 localhost pluto[16393]: | encrypting 24 using OAKLEY_3DES_CBC
Jul  7 09:41:17 localhost pluto[16393]: | next IV:  1d 3a 53 27  d8 3f 63 23
Jul  7 09:41:17 localhost pluto[16393]: | emitting length of ISAKMP Message: 52
Jul  7 09:41:17 localhost pluto[16393]: | inR1_outI2: instance vpn-connection[0], setting newest_ipsec_sa to #2 (was #0) (spd.eroute=#2)
Jul  7 09:41:17 localhost pluto[16393]: | complete state transition with STF_OK
Jul  7 09:41:17 localhost pluto[16393]: "vpn-connection" #2: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2
Jul  7 09:41:17 localhost pluto[16393]: | deleting event for #2
Jul  7 09:41:17 localhost pluto[16393]: | sending reply packet to 12.13.14.15:500 (from port 500)
Jul  7 09:41:17 localhost pluto[16393]: | sending 52 bytes for STATE_QUICK_I1 through eth0:500 to 12.13.14.15:500 (using #2)
Jul  7 09:41:17 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3  88 aa 62 f5  46 d0 50 23
Jul  7 09:41:17 localhost pluto[16393]: |   08 10 20 01  5a a5 0d 23  00 00 00 34  c5 ed 3e e5
Jul  7 09:41:17 localhost pluto[16393]: |   25 2d 07 a1  7b 39 ed c5  20 79 6a 5a  1d 3a 53 27
Jul  7 09:41:17 localhost pluto[16393]: |   d8 3f 63 23
Jul  7 09:41:17 localhost pluto[16393]: | inserting event EVENT_SA_REPLACE, timeout in 28108 seconds for #2
Jul  7 09:41:17 localhost pluto[16393]: | event added after event EVENT_REINIT_SECRET
Jul  7 09:41:17 localhost pluto[16393]: "vpn-connection" #2: STATE_QUICK_I2: sent QI2, IPsec SA established tunnel mode {ESP/NAT=>0x5cf54fe1 <0x176959fd xfrm=3DES_0-HMAC_SHA1 NATOA=none NATD=none DPD=none}
Jul  7 09:41:17 localhost pluto[16393]: | modecfg pull: noquirk policy:push not-client
Jul  7 09:41:17 localhost pluto[16393]: | phase 1 is done, looking for phase 2 to unpend
Jul  7 09:41:17 localhost pluto[16393]: | * processed 1 messages from cryptographic helpers 
Jul  7 09:41:17 localhost pluto[16393]: | next event EVENT_PENDING_DDNS in 35 seconds
Jul  7 09:41:17 localhost pluto[16393]: | next event EVENT_PENDING_DDNS in 35 seconds
Jul  7 09:41:52 localhost pluto[16393]: |  
Jul  7 09:41:52 localhost pluto[16393]: | next event EVENT_PENDING_DDNS in 0 seconds
Jul  7 09:41:52 localhost pluto[16393]: | *time to handle event
Jul  7 09:41:52 localhost pluto[16393]: | handling event EVENT_PENDING_DDNS
Jul  7 09:41:52 localhost pluto[16393]: | event after this is EVENT_PENDING_PHASE2 in 0 seconds
Jul  7 09:41:52 localhost pluto[16393]: | inserting event EVENT_PENDING_DDNS, timeout in 60 seconds
Jul  7 09:41:52 localhost pluto[16393]: | event added after event EVENT_PENDING_PHASE2
Jul  7 09:41:52 localhost pluto[16393]: | handling event EVENT_PENDING_PHASE2
Jul  7 09:41:52 localhost pluto[16393]: | event after this is EVENT_PENDING_DDNS in 60 seconds
Jul  7 09:41:52 localhost pluto[16393]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
Jul  7 09:41:52 localhost pluto[16393]: | event added after event EVENT_PENDING_DDNS
Jul  7 09:41:52 localhost pluto[16393]: | pending review: connection "vpn-connection" checked
Jul  7 09:41:52 localhost pluto[16393]: | next event EVENT_PENDING_DDNS in 60 seconds
Jul  7 09:42:28 localhost pluto[16393]: |  
Jul  7 09:42:28 localhost pluto[16393]: | *received whack message
Jul  7 09:42:28 localhost pluto[16393]: shutting down
Jul  7 09:42:28 localhost pluto[16393]: forgetting secrets
Jul  7 09:42:28 localhost pluto[16393]: | processing connection vpn-connection
Jul  7 09:42:28 localhost pluto[16393]: "vpn-connection": deleting connection
Jul  7 09:42:28 localhost pluto[16393]: | processing connection vpn-connection
Jul  7 09:42:28 localhost pluto[16393]: "vpn-connection" #2: deleting state (STATE_QUICK_I2)
Jul  7 09:42:28 localhost pluto[16393]: | deleting event for #2
Jul  7 09:42:28 localhost pluto[16393]: | deleting state #2
Jul  7 09:42:28 localhost pluto[16393]: | **emit ISAKMP Message:
Jul  7 09:42:28 localhost pluto[16393]: |    initiator cookie:
Jul  7 09:42:28 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3
Jul  7 09:42:28 localhost pluto[16393]: |    responder cookie:
Jul  7 09:42:28 localhost pluto[16393]: |   88 aa 62 f5  46 d0 50 23
Jul  7 09:42:28 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_HASH
Jul  7 09:42:28 localhost pluto[16393]: |    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
Jul  7 09:42:28 localhost pluto[16393]: |    exchange type: ISAKMP_XCHG_INFO
Jul  7 09:42:28 localhost pluto[16393]: |    flags: ISAKMP_FLAG_ENCRYPTION
Jul  7 09:42:28 localhost pluto[16393]: |    message ID:  22 0a d3 19
Jul  7 09:42:28 localhost pluto[16393]: | ***emit ISAKMP Hash Payload:
Jul  7 09:42:28 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_D
Jul  7 09:42:28 localhost pluto[16393]: | emitting 20 zero bytes of HASH(1) into ISAKMP Hash Payload
Jul  7 09:42:28 localhost pluto[16393]: | emitting length of ISAKMP Hash Payload: 24
Jul  7 09:42:28 localhost pluto[16393]: | ***emit ISAKMP Delete Payload:
Jul  7 09:42:28 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:42:28 localhost pluto[16393]: |    DOI: ISAKMP_DOI_IPSEC
Jul  7 09:42:28 localhost pluto[16393]: |    protocol ID: 3
Jul  7 09:42:28 localhost pluto[16393]: |    SPI size: 4
Jul  7 09:42:28 localhost pluto[16393]: |    number of SPIs: 1
Jul  7 09:42:28 localhost pluto[16393]: | emitting 4 raw bytes of delete payload into ISAKMP Delete Payload
Jul  7 09:42:28 localhost pluto[16393]: | delete payload  17 69 59 fd
Jul  7 09:42:28 localhost pluto[16393]: | emitting length of ISAKMP Delete Payload: 16
Jul  7 09:42:28 localhost pluto[16393]: | HASH(1) computed:
Jul  7 09:42:28 localhost pluto[16393]: |   d4 ff 17 84  d4 8e 78 ba  11 a4 ba ce  89 3f 62 d5
Jul  7 09:42:28 localhost pluto[16393]: |   ce 1a ca 94
Jul  7 09:42:28 localhost pluto[16393]: | last Phase 1 IV:  9c 26 ce 6a  73 a6 1a c6
Jul  7 09:42:28 localhost pluto[16393]: | current Phase 1 IV:  9c 26 ce 6a  73 a6 1a c6
Jul  7 09:42:28 localhost pluto[16393]: | computed Phase 2 IV:
Jul  7 09:42:28 localhost pluto[16393]: |   0b b0 d9 ca  07 58 28 4b  6d 31 e5 8d  da b4 0f c4
Jul  7 09:42:28 localhost pluto[16393]: |   fa a6 31 6c
Jul  7 09:42:28 localhost pluto[16393]: | encrypting:
Jul  7 09:42:28 localhost pluto[16393]: |   0c 00 00 18  d4 ff 17 84  d4 8e 78 ba  11 a4 ba ce
Jul  7 09:42:28 localhost pluto[16393]: |   89 3f 62 d5  ce 1a ca 94  00 00 00 10  00 00 00 01
Jul  7 09:42:28 localhost pluto[16393]: |   03 04 00 01  17 69 59 fd
Jul  7 09:42:28 localhost pluto[16393]: | IV:
Jul  7 09:42:28 localhost pluto[16393]: |   0b b0 d9 ca  07 58 28 4b  6d 31 e5 8d  da b4 0f c4
Jul  7 09:42:28 localhost pluto[16393]: |   fa a6 31 6c
Jul  7 09:42:28 localhost pluto[16393]: | unpadded size is: 40
Jul  7 09:42:28 localhost pluto[16393]: | encrypting 40 using OAKLEY_3DES_CBC
Jul  7 09:42:28 localhost pluto[16393]: | next IV:  22 f0 a0 64  22 ea 93 dc
Jul  7 09:42:28 localhost pluto[16393]: | emitting length of ISAKMP Message: 68
Jul  7 09:42:28 localhost pluto[16393]: | sending 68 bytes for delete notify through eth0:500 to 12.13.14.15:500 (using #1)
Jul  7 09:42:28 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3  88 aa 62 f5  46 d0 50 23
Jul  7 09:42:28 localhost pluto[16393]: |   08 10 05 01  22 0a d3 19  00 00 00 44  36 ef a7 21
Jul  7 09:42:28 localhost pluto[16393]: |   4e 4a cc 55  5c 53 8d 1f  81 3f 77 ef  1c a9 85 5f
Jul  7 09:42:28 localhost pluto[16393]: |   51 95 07 ed  76 39 02 63  a4 15 68 bd  22 f0 a0 64
Jul  7 09:42:28 localhost pluto[16393]: |   22 ea 93 dc
Jul  7 09:42:28 localhost pluto[16393]: | deleting event for #2
Jul  7 09:42:28 localhost pluto[16393]: | no suspended cryptographic state for 2 
Jul  7 09:42:28 localhost pluto[16393]: | ICOOKIE:  1a 43 d8 0b  81 36 b0 c3
Jul  7 09:42:28 localhost pluto[16393]: | RCOOKIE:  88 aa 62 f5  46 d0 50 23
Jul  7 09:42:28 localhost pluto[16393]: | state hash entry 30
Jul  7 09:42:28 localhost pluto[16393]: | command executing down-host
Jul  7 09:42:28 localhost pluto[16393]: | executing down-host: 2>&1 PLUTO_VERB='down-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='vpn-connection' PLUTO_INTERFACE='eth0' PLUTO_NEXT_HOP='12.13.14.15' PLUTO_ME='192.168.25.77' PLUTO_MY_ID='192.168.25.77' PLUTO_MY_CLIENT='192.168.25.77/32' PLUTO_MY_CLIENT_NET='192.168.25.77' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='12.13.14.15' PLUTO_PEER_ID='12.13.14.15' PLUTO_PEER_CLIENT='192.168.66.77/32' PLUTO_PEER_CLIENT_NET='192.168.66.77' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW' PLUTO_XAUTH_USERNAME=''  ipsec _updown
Jul  7 09:42:28 localhost pluto[16393]: | popen(): cmd is 678 chars long
Jul  7 09:42:28 localhost pluto[16393]: | cmd(   0):2>&1 PLUTO_VERB='down-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='vpn-connection' :
Jul  7 09:42:28 localhost pluto[16393]: | cmd(  80):PLUTO_INTERFACE='eth0' PLUTO_NEXT_HOP='12.13.14.15' PLUTO_ME='192.168.25.77' PL:
Jul  7 09:42:28 localhost pluto[16393]: | cmd( 160):UTO_MY_ID='192.168.25.77' PLUTO_MY_CLIENT='192.168.25.77/32' PLUTO_MY_CLIENT_NET=':
Jul  7 09:42:28 localhost pluto[16393]: | cmd( 240):192.168.25.77' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_:
Jul  7 09:42:28 localhost pluto[16393]: | cmd( 320):PROTOCOL='0' PLUTO_PEER='12.13.14.15' PLUTO_PEER_ID='12.13.14.15' PLUTO_PEER:
Jul  7 09:42:28 localhost pluto[16393]: | cmd( 400):_CLIENT='192.168.66.77/32' PLUTO_PEER_CLIENT_NET='192.168.66.77' PLUTO_PEER_CLIENT_MAS:
Jul  7 09:42:28 localhost pluto[16393]: | cmd( 480):K='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='':
Jul  7 09:42:28 localhost pluto[16393]: | cmd( 560): PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW' :
Jul  7 09:42:28 localhost pluto[16393]: | cmd( 640):PLUTO_XAUTH_USERNAME=''  ipsec _updown:
Jul  7 09:42:29 localhost pluto[16393]: | request to replace with shunt a prospective erouted policy with netkey kernel --- experimental
Jul  7 09:42:29 localhost pluto[16393]: | delete esp.5cf54fe1 at 12.13.14.15
Jul  7 09:42:29 localhost pluto[16393]: | delete inbound eroute 192.168.66.77/32:0 --0-> 192.168.25.77/32:0 => unk255.10000 at 192.168.25.77 (raw_eroute)
Jul  7 09:42:29 localhost pluto[16393]: | raw_eroute result=1 
Jul  7 09:42:29 localhost pluto[16393]: | delete esp.176959fd at 192.168.25.77
Jul  7 09:42:29 localhost pluto[16393]: | processing connection vpn-connection
Jul  7 09:42:29 localhost pluto[16393]: "vpn-connection" #1: deleting state (STATE_MAIN_I4)
Jul  7 09:42:29 localhost pluto[16393]: | deleting event for #1
Jul  7 09:42:29 localhost pluto[16393]: | deleting state #1
Jul  7 09:42:29 localhost pluto[16393]: | **emit ISAKMP Message:
Jul  7 09:42:29 localhost pluto[16393]: |    initiator cookie:
Jul  7 09:42:29 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3
Jul  7 09:42:29 localhost pluto[16393]: |    responder cookie:
Jul  7 09:42:29 localhost pluto[16393]: |   88 aa 62 f5  46 d0 50 23
Jul  7 09:42:29 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_HASH
Jul  7 09:42:29 localhost pluto[16393]: |    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
Jul  7 09:42:29 localhost pluto[16393]: |    exchange type: ISAKMP_XCHG_INFO
Jul  7 09:42:29 localhost pluto[16393]: |    flags: ISAKMP_FLAG_ENCRYPTION
Jul  7 09:42:29 localhost pluto[16393]: |    message ID:  2c 5e fb b9
Jul  7 09:42:29 localhost pluto[16393]: | ***emit ISAKMP Hash Payload:
Jul  7 09:42:29 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_D
Jul  7 09:42:29 localhost pluto[16393]: | emitting 20 zero bytes of HASH(1) into ISAKMP Hash Payload
Jul  7 09:42:29 localhost pluto[16393]: | emitting length of ISAKMP Hash Payload: 24
Jul  7 09:42:29 localhost pluto[16393]: | ***emit ISAKMP Delete Payload:
Jul  7 09:42:29 localhost pluto[16393]: |    next payload type: ISAKMP_NEXT_NONE
Jul  7 09:42:29 localhost pluto[16393]: |    DOI: ISAKMP_DOI_IPSEC
Jul  7 09:42:29 localhost pluto[16393]: |    protocol ID: 1
Jul  7 09:42:29 localhost pluto[16393]: |    SPI size: 16
Jul  7 09:42:29 localhost pluto[16393]: |    number of SPIs: 1
Jul  7 09:42:29 localhost pluto[16393]: | emitting 16 raw bytes of delete payload into ISAKMP Delete Payload
Jul  7 09:42:29 localhost pluto[16393]: | delete payload  1a 43 d8 0b  81 36 b0 c3  88 aa 62 f5  46 d0 50 23
Jul  7 09:42:29 localhost pluto[16393]: | emitting length of ISAKMP Delete Payload: 28
Jul  7 09:42:29 localhost pluto[16393]: | HASH(1) computed:
Jul  7 09:42:29 localhost pluto[16393]: |   b4 82 4e 30  bf ef c8 b6  0c 0a 1e 97  d8 fb bc 62
Jul  7 09:42:29 localhost pluto[16393]: |   92 98 d1 02
Jul  7 09:42:29 localhost pluto[16393]: | last Phase 1 IV:  9c 26 ce 6a  73 a6 1a c6
Jul  7 09:42:29 localhost pluto[16393]: | current Phase 1 IV:  9c 26 ce 6a  73 a6 1a c6
Jul  7 09:42:29 localhost pluto[16393]: | computed Phase 2 IV:
Jul  7 09:42:29 localhost pluto[16393]: |   33 c4 6e d9  87 5d bc ad  93 37 b8 d6  2c c5 7b 5a
Jul  7 09:42:29 localhost pluto[16393]: |   3d 3f 0c e3
Jul  7 09:42:29 localhost pluto[16393]: | encrypting:
Jul  7 09:42:29 localhost pluto[16393]: |   0c 00 00 18  b4 82 4e 30  bf ef c8 b6  0c 0a 1e 97
Jul  7 09:42:29 localhost pluto[16393]: |   d8 fb bc 62  92 98 d1 02  00 00 00 1c  00 00 00 01
Jul  7 09:42:29 localhost pluto[16393]: |   01 10 00 01  1a 43 d8 0b  81 36 b0 c3  88 aa 62 f5
Jul  7 09:42:29 localhost pluto[16393]: |   46 d0 50 23
Jul  7 09:42:29 localhost pluto[16393]: | IV:
Jul  7 09:42:29 localhost pluto[16393]: |   33 c4 6e d9  87 5d bc ad  93 37 b8 d6  2c c5 7b 5a
Jul  7 09:42:29 localhost pluto[16393]: |   3d 3f 0c e3
Jul  7 09:42:29 localhost pluto[16393]: | unpadded size is: 52
Jul  7 09:42:29 localhost pluto[16393]: | emitting 4 zero bytes of encryption padding into ISAKMP Message
Jul  7 09:42:29 localhost pluto[16393]: | encrypting 56 using OAKLEY_3DES_CBC
Jul  7 09:42:29 localhost pluto[16393]: | next IV:  72 bd d1 00  f8 9b 1f e3
Jul  7 09:42:29 localhost pluto[16393]: | emitting length of ISAKMP Message: 84
Jul  7 09:42:29 localhost pluto[16393]: | sending 84 bytes for delete notify through eth0:500 to 12.13.14.15:500 (using #1)
Jul  7 09:42:29 localhost pluto[16393]: |   1a 43 d8 0b  81 36 b0 c3  88 aa 62 f5  46 d0 50 23
Jul  7 09:42:29 localhost pluto[16393]: |   08 10 05 01  2c 5e fb b9  00 00 00 54  94 f1 12 50
Jul  7 09:42:29 localhost pluto[16393]: |   c8 f8 ca 1c  e1 d7 0c 45  fd 7f ed 13  1d d7 7d 4b
Jul  7 09:42:29 localhost pluto[16393]: |   ea 11 8f f2  52 c3 ed ae  b3 88 86 05  24 90 0b 40
Jul  7 09:42:29 localhost pluto[16393]: |   fa c6 32 e3  0d cb 8f b0  60 bb 19 4e  72 bd d1 00
Jul  7 09:42:29 localhost pluto[16393]: |   f8 9b 1f e3
Jul  7 09:42:29 localhost pluto[16393]: | deleting event for #1
Jul  7 09:42:29 localhost pluto[16393]: | no suspended cryptographic state for 1 
Jul  7 09:42:29 localhost pluto[16393]: | ICOOKIE:  1a 43 d8 0b  81 36 b0 c3
Jul  7 09:42:29 localhost pluto[16393]: | RCOOKIE:  88 aa 62 f5  46 d0 50 23
Jul  7 09:42:29 localhost pluto[16393]: | state hash entry 30
Jul  7 09:42:29 localhost pluto[16393]: | request to delete a unrouted policy with netkey kernel --- experimental
Jul  7 09:42:29 localhost pluto[16393]: | route owner of "vpn-connection" unrouted: NULL
Jul  7 09:42:29 localhost pluto[16393]: | command executing unroute-host
Jul  7 09:42:29 localhost pluto[16393]: | executing unroute-host: 2>&1 PLUTO_VERB='unroute-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='vpn-connection' PLUTO_INTERFACE='eth0' PLUTO_NEXT_HOP='12.13.14.15' PLUTO_ME='192.168.25.77' PLUTO_MY_ID='192.168.25.77' PLUTO_MY_CLIENT='192.168.25.77/32' PLUTO_MY_CLIENT_NET='192.168.25.77' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='12.13.14.15' PLUTO_PEER_ID='12.13.14.15' PLUTO_PEER_CLIENT='192.168.66.77/32' PLUTO_PEER_CLIENT_NET='192.168.66.77' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW'   ipsec _updown
Jul  7 09:42:29 localhost pluto[16393]: | popen(): cmd is 658 chars long
Jul  7 09:42:29 localhost pluto[16393]: | cmd(   0):2>&1 PLUTO_VERB='unroute-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='vpn-connectio:
Jul  7 09:42:29 localhost pluto[16393]: | cmd(  80):n' PLUTO_INTERFACE='eth0' PLUTO_NEXT_HOP='12.13.14.15' PLUTO_ME='192.168.25.77':
Jul  7 09:42:29 localhost pluto[16393]: | cmd( 160): PLUTO_MY_ID='192.168.25.77' PLUTO_MY_CLIENT='192.168.25.77/32' PLUTO_MY_CLIENT_NE:
Jul  7 09:42:29 localhost pluto[16393]: | cmd( 240):T='192.168.25.77' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_:
Jul  7 09:42:29 localhost pluto[16393]: | cmd( 320):MY_PROTOCOL='0' PLUTO_PEER='12.13.14.15' PLUTO_PEER_ID='12.13.14.15' PLUTO_P:
Jul  7 09:42:29 localhost pluto[16393]: | cmd( 400):EER_CLIENT='192.168.66.77/32' PLUTO_PEER_CLIENT_NET='192.168.66.77' PLUTO_PEER_CLIENT_:
Jul  7 09:42:29 localhost pluto[16393]: | cmd( 480):MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA:
Jul  7 09:42:29 localhost pluto[16393]: | cmd( 560):='' PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLO:
Jul  7 09:42:29 localhost pluto[16393]: | cmd( 640):W'   ipsec _updown:
Jul  7 09:42:29 localhost pluto[16393]: | alg_info_delref(0x8cf97b0) alg_info->ref_cnt=2
Jul  7 09:42:29 localhost pluto[16393]: | alg_info_delref(0x8cf8f50) alg_info->ref_cnt=2
Jul  7 09:42:29 localhost pluto[16393]: shutting down interface lo/lo ::1:500
Jul  7 09:42:29 localhost pluto[16393]: shutting down interface lo/lo 127.0.0.1:4500
Jul  7 09:42:29 localhost pluto[16393]: shutting down interface lo/lo 127.0.0.1:500
Jul  7 09:42:29 localhost pluto[16393]: shutting down interface eth0/eth0 192.168.25.77:4500
Jul  7 09:42:29 localhost pluto[16393]: shutting down interface eth0/eth0 192.168.25.77:500
Jul  7 09:42:29 localhost pluto[16401]: pluto_crypto_helper: helper (0) is  normal exiting 


More information about the Users mailing list