Attachment 300179 Details for Bug 438826 – Responder (tim-hv4) logs

Responder (tim-hv4) logs

responder.tim-hv4.log (text/plain), 43.25 KB, created by IBM Bug Proxy on 2008-04-03 05:25:17 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: IBM Bug Proxy

Created: 2008-04-03 05:25:17 UTC

Size: 43.25 KB

patch

obsolete

>
>Apr  2 23:45:55 tim-hv4 ipsec__plutorun: Starting Pluto subsystem...
>Apr  2 23:45:55 tim-hv4 pluto[28225]: Starting Pluto (Openswan Version 2.6.09; Vendor ID OEZD~MT}mAnl) pid:28225
>Apr  2 23:45:55 tim-hv4 pluto[28225]: Setting NAT-Traversal port-4500 floating to on
>Apr  2 23:45:55 tim-hv4 pluto[28225]:    port floating activation criteria nat_t=1/port_float=1
>Apr  2 23:45:55 tim-hv4 pluto[28225]:    including NAT-Traversal patch (Version 0.6c)
>Apr  2 23:45:55 tim-hv4 pluto[28225]: | opening /dev/urandom
>Apr  2 23:45:55 tim-hv4 pluto[28225]: using /dev/urandom as source of random entropy
>Apr  2 23:45:55 tim-hv4 pluto[28225]: | inserting event EVENT_REINIT_SECRET, timeout in 3600 seconds
>Apr  2 23:45:55 tim-hv4 pluto[28225]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>Apr  2 23:45:55 tim-hv4 pluto[28225]: ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC_SSH: Ok (ret=0)
>Apr  2 23:45:55 tim-hv4 pluto[28225]: ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC: Ok (ret=0)
>Apr  2 23:45:55 tim-hv4 pluto[28225]: ike_alg_register_enc(): Activating OAKLEY_SERPENT_CBC: Ok (ret=0)
>Apr  2 23:45:55 tim-hv4 pluto[28225]: ike_alg_register_enc(): Activating OAKLEY_AES_CBC: Ok (ret=0)
>Apr  2 23:45:55 tim-hv4 pluto[28225]: ike_alg_register_enc(): Activating OAKLEY_BLOWFISH_CBC: Ok (ret=0)
>Apr  2 23:45:55 tim-hv4 pluto[28225]: ike_alg_register_hash(): Activating OAKLEY_SHA2_512: Ok (ret=0)
>Apr  2 23:45:55 tim-hv4 pluto[28225]: ike_alg_register_hash(): Activating OAKLEY_SHA2_256: Ok (ret=0)
>Apr  2 23:45:55 tim-hv4 pluto[28225]: starting up 7 cryptographic helpers
>Apr  2 23:45:55 tim-hv4 pluto[28225]: started helper pid=28237 (fd:7)
>Apr  2 23:45:55 tim-hv4 pluto[28237]: | opening /dev/urandom
>Apr  2 23:45:55 tim-hv4 pluto[28225]: started helper pid=28239 (fd:8)
>Apr  2 23:45:55 tim-hv4 pluto[28239]: | opening /dev/urandom
>Apr  2 23:45:55 tim-hv4 pluto[28237]: using /dev/urandom as source of random entropy
>Apr  2 23:45:55 tim-hv4 pluto[28240]: | opening /dev/urandom
>Apr  2 23:45:55 tim-hv4 pluto[28225]: started helper pid=28240 (fd:9)
>Apr  2 23:45:55 tim-hv4 pluto[28239]: using /dev/urandom as source of random entropy
>Apr  2 23:45:55 tim-hv4 pluto[28237]: ! helper 0 waiting on fd: 8
>Apr  2 23:45:55 tim-hv4 pluto[28240]: using /dev/urandom as source of random entropy
>Apr  2 23:45:56 tim-hv4 pluto[28225]: started helper pid=28241 (fd:10)
>Apr  2 23:45:56 tim-hv4 pluto[28241]: | opening /dev/urandom
>Apr  2 23:45:56 tim-hv4 pluto[28239]: ! helper 1 waiting on fd: 9
>Apr  2 23:45:56 tim-hv4 pluto[28240]: ! helper 2 waiting on fd: 10
>Apr  2 23:45:56 tim-hv4 pluto[28225]: started helper pid=28242 (fd:11)
>Apr  2 23:45:56 tim-hv4 pluto[28242]: | opening /dev/urandom
>Apr  2 23:45:56 tim-hv4 pluto[28241]: using /dev/urandom as source of random entropy
>Apr  2 23:45:56 tim-hv4 pluto[28225]: started helper pid=28243 (fd:12)
>Apr  2 23:45:56 tim-hv4 pluto[28243]: | opening /dev/urandom
>Apr  2 23:45:56 tim-hv4 pluto[28242]: using /dev/urandom as source of random entropy
>Apr  2 23:45:56 tim-hv4 pluto[28241]: ! helper 3 waiting on fd: 11
>Apr  2 23:45:56 tim-hv4 pluto[28225]: started helper pid=28244 (fd:13)
>Apr  2 23:45:56 tim-hv4 pluto[28244]: | opening /dev/urandom
>Apr  2 23:45:56 tim-hv4 pluto[28243]: using /dev/urandom as source of random entropy
>Apr  2 23:45:56 tim-hv4 pluto[28242]: ! helper 4 waiting on fd: 12
>Apr  2 23:45:56 tim-hv4 pluto[28225]: Using Linux 2.6 IPsec interface code on 2.6.18-86.el5 (experimental code)
>Apr  2 23:45:56 tim-hv4 pluto[28244]: using /dev/urandom as source of random entropy
>Apr  2 23:45:56 tim-hv4 pluto[28243]: ! helper 5 waiting on fd: 13
>Apr  2 23:45:56 tim-hv4 pluto[28225]: | process 28225 listening for PF_KEY_V2 on file descriptor 16
>Apr  2 23:45:56 tim-hv4 pluto[28244]: ! helper 6 waiting on fd: 14
>Apr  2 23:45:56 tim-hv4 pluto[28225]: | finish_pfkey_msg: SADB_REGISTER message 1 for AH 
>Apr  2 23:45:56 tim-hv4 pluto[28225]: |   02 07 00 02  00 02 00 00  00 00 00 01  00 00 6e 41
>Apr  2 23:45:56 tim-hv4 pluto[28225]: | pfkey_get: SADB_REGISTER message 1
>Apr  2 23:45:56 tim-hv4 pluto[28225]: | AH registered with kernel.
>Apr  2 23:45:56 tim-hv4 pluto[28225]: | finish_pfkey_msg: SADB_REGISTER message 2 for ESP 
>Apr  2 23:45:56 tim-hv4 pluto[28225]: |   02 07 00 03  00 02 00 00  00 00 00 02  00 00 6e 41
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | pfkey_get: SADB_REGISTER message 2
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | alg_init():memset(0x8111c48, 0, 2016) memset(0x8112428, 0, 2048) 
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: sadb_msg_len=19 sadb_supported_len=56
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_add():satype=3, exttype=14, alg_id=251
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[0], exttype=14, satype=3, alg_id=251, alg_ivlen=0, alg_minbits=0, alg_maxbits=0, res=0, ret=1
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_add():satype=3, exttype=14, alg_id=2
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[1], exttype=14, satype=3, alg_id=2, alg_ivlen=0, alg_minbits=128, alg_maxbits=128, res=0, ret=1
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_add():satype=3, exttype=14, alg_id=3
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[2], exttype=14, satype=3, alg_id=3, alg_ivlen=0, alg_minbits=160, alg_maxbits=160, res=0, ret=1
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_add():satype=3, exttype=14, alg_id=5
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[3], exttype=14, satype=3, alg_id=5, alg_ivlen=0, alg_minbits=256, alg_maxbits=256, res=0, ret=1
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_add():satype=3, exttype=14, alg_id=8
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[4], exttype=14, satype=3, alg_id=8, alg_ivlen=0, alg_minbits=160, alg_maxbits=160, res=0, ret=1
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_add():satype=3, exttype=14, alg_id=9
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[5], exttype=14, satype=3, alg_id=9, alg_ivlen=0, alg_minbits=128, alg_maxbits=128, res=0, ret=1
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: sadb_msg_len=19 sadb_supported_len=80
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_add():satype=3, exttype=15, alg_id=11
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[6], exttype=15, satype=3, alg_id=11, alg_ivlen=0, alg_minbits=0, alg_maxbits=0, res=0, ret=1
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_add():satype=3, exttype=15, alg_id=2
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[7], exttype=15, satype=3, alg_id=2, alg_ivlen=8, alg_minbits=64, alg_maxbits=64, res=0, ret=1
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_add():satype=3, exttype=15, alg_id=3
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[8], exttype=15, satype=3, alg_id=3, alg_ivlen=8, alg_minbits=192, alg_maxbits=192, res=0, ret=1
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_add():satype=3, exttype=15, alg_id=6
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[9], exttype=15, satype=3, alg_id=6, alg_ivlen=8, alg_minbits=40, alg_maxbits=128, res=0, ret=1
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_add():satype=3, exttype=15, alg_id=7
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[10], exttype=15, satype=3, alg_id=7, alg_ivlen=8, alg_minbits=40, alg_maxbits=448, res=0, ret=1
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_add():satype=3, exttype=15, alg_id=12
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[11], exttype=15, satype=3, alg_id=12, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_add():satype=3, exttype=15, alg_id=252
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[12], exttype=15, satype=3, alg_id=252, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_add():satype=3, exttype=15, alg_id=253
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[13], exttype=15, satype=3, alg_id=253, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_add():satype=3, exttype=15, alg_id=13
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[14], exttype=15, satype=3, alg_id=13, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | ESP registered with kernel.
>Apr  2 23:45:57 tim-hv4 pluto[28225]: | finish_pfkey_msg: SADB_REGISTER message 3 for IPCOMP 
>Apr  2 23:45:57 tim-hv4 pluto[28225]: |   02 07 00 09  00 02 00 00  00 00 00 03  00 00 6e 41
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | pfkey_get: SADB_REGISTER message 3
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | IPCOMP registered with kernel.
>Apr  2 23:45:58 tim-hv4 pluto[28225]: Could not change to directory '/etc/ipsec.d/cacerts': /
>Apr  2 23:45:58 tim-hv4 pluto[28225]: Could not change to directory '/etc/ipsec.d/aacerts': /
>Apr  2 23:45:58 tim-hv4 pluto[28225]: Could not change to directory '/etc/ipsec.d/ocspcerts': /
>Apr  2 23:45:58 tim-hv4 pluto[28225]: Could not change to directory '/etc/ipsec.d/crls'
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | inserting event EVENT_LOG_DAILY, timeout in 842 seconds
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | next event EVENT_PENDING_PHASE2 in 117 seconds
>Apr  2 23:45:58 tim-hv4 pluto[28225]: |  
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | *received whack message
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | Added new connection i386-ppc with policy PSK+ENCRYPT+TUNNEL+PFS+!IKEv1+IKEv2ALLOW+IKEv2Init
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | counting wild cards for 9.3.190.198 is 0
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | counting wild cards for 9.3.192.210 is 0
>Apr  2 23:45:58 tim-hv4 pluto[28225]: added connection description "i386-ppc"
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | 9.3.190.198<9.3.190.198>[S=C]...9.3.192.210<9.3.192.210>[S=C]
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | ike_life: 3600s; ipsec_life: 28800s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 3; policy: PSK+ENCRYPT+TUNNEL+PFS+!IKEv1+IKEv2ALLOW+IKEv2Init
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | * processed 0 messages from cryptographic helpers 
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | next event EVENT_PENDING_PHASE2 in 117 seconds
>Apr  2 23:45:58 tim-hv4 pluto[28225]: |  
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | *received whack message
>Apr  2 23:45:58 tim-hv4 pluto[28225]: listening for IKE messages
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | found lo with address 127.0.0.1
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | found eth0 with address 9.3.192.210
>Apr  2 23:45:58 tim-hv4 pluto[28225]: adding interface eth0/eth0 9.3.192.210:500
>Apr  2 23:45:58 tim-hv4 pluto[28225]: adding interface eth0/eth0 9.3.192.210:4500
>Apr  2 23:45:58 tim-hv4 pluto[28225]: adding interface lo/lo 127.0.0.1:500
>Apr  2 23:45:58 tim-hv4 pluto[28225]: adding interface lo/lo 127.0.0.1:4500
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | found lo with address 0000:0000:0000:0000:0000:0000:0000:0001
>Apr  2 23:45:58 tim-hv4 pluto[28225]: adding interface lo/lo ::1:500
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | connect_to_host_pair: 9.3.192.210:500 9.3.190.198:500 -> hp:none 
>Apr  2 23:45:58 tim-hv4 pluto[28225]: loading secrets from "/etc/ipsec.secrets"
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | id type added to secret(0x8121f18) 1: 9.3.190.198
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | id type added to secret(0x8121f18) 1: 9.3.192.210
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | Processing PSK at line 1: passed
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | * processed 0 messages from cryptographic helpers 
>Apr  2 23:45:58 tim-hv4 pluto[28225]: | next event EVENT_PENDING_PHASE2 in 117 seconds
>Apr  2 23:47:55 tim-hv4 pluto[28225]: |  
>Apr  2 23:47:55 tim-hv4 pluto[28225]: | *time to handle event
>Apr  2 23:47:55 tim-hv4 pluto[28225]: | handling event EVENT_PENDING_PHASE2
>Apr  2 23:47:55 tim-hv4 pluto[28225]: | event after this is EVENT_LOG_DAILY in 725 seconds
>Apr  2 23:47:55 tim-hv4 pluto[28225]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>Apr  2 23:47:55 tim-hv4 pluto[28225]: | pending review: connection "i386-ppc" was not up, skipped
>Apr  2 23:47:55 tim-hv4 pluto[28225]: | next event EVENT_PENDING_PHASE2 in 120 seconds
>Apr  2 23:49:55 tim-hv4 pluto[28225]: |  
>Apr  2 23:49:55 tim-hv4 pluto[28225]: | *time to handle event
>Apr  2 23:49:55 tim-hv4 pluto[28225]: | handling event EVENT_PENDING_PHASE2
>Apr  2 23:49:55 tim-hv4 pluto[28225]: | event after this is EVENT_LOG_DAILY in 605 seconds
>Apr  2 23:49:55 tim-hv4 pluto[28225]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>Apr  2 23:49:55 tim-hv4 pluto[28225]: | pending review: connection "i386-ppc" was not up, skipped
>Apr  2 23:49:55 tim-hv4 pluto[28225]: | next event EVENT_PENDING_PHASE2 in 120 seconds
>Apr  2 23:51:55 tim-hv4 pluto[28225]: |  
>Apr  2 23:51:55 tim-hv4 pluto[28225]: | *time to handle event
>Apr  2 23:51:55 tim-hv4 pluto[28225]: | handling event EVENT_PENDING_PHASE2
>Apr  2 23:51:55 tim-hv4 pluto[28225]: | event after this is EVENT_LOG_DAILY in 485 seconds
>Apr  2 23:51:55 tim-hv4 pluto[28225]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>Apr  2 23:51:55 tim-hv4 pluto[28225]: | pending review: connection "i386-ppc" was not up, skipped
>Apr  2 23:51:55 tim-hv4 pluto[28225]: | next event EVENT_PENDING_PHASE2 in 120 seconds
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |  
>Apr  2 23:53:34 tim-hv4 pluto[28225]: | *received 668 bytes from 9.3.190.198:500 on eth0 (port=500)
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   b8 54 f1 5d  1b 93 75 ac  00 00 00 00  00 00 00 00
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   21 20 22 08  00 00 00 00  00 00 02 9c  22 80 01 94
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   02 00 00 28  01 01 00 04  03 00 00 08  01 00 00 0c
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   03 00 00 08  03 00 00 02  03 00 00 08  02 00 00 02
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   00 00 00 08  04 00 00 05  02 00 00 28  02 01 00 04
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   03 00 00 08  01 00 00 0c  03 00 00 08  03 00 00 02
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   03 00 00 08  02 00 00 01  00 00 00 08  04 00 00 05
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   02 00 00 28  03 01 00 04  03 00 00 08  01 00 00 03
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   03 00 00 08  03 00 00 02  03 00 00 08  02 00 00 02
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   00 00 00 08  04 00 00 05  02 00 00 28  04 01 00 04
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   03 00 00 08  01 00 00 03  03 00 00 08  03 00 00 02
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   03 00 00 08  02 00 00 01  00 00 00 08  04 00 00 05
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   02 00 00 28  05 01 00 04  03 00 00 08  01 00 00 03
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   03 00 00 08  03 00 00 02  03 00 00 08  02 00 00 02
>Apr  2 23:53:34 tim-hv4 charon: 09[AUD] 9.3.190.198 is initiating an IKE_SA 
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   00 00 00 08  04 00 00 02  02 00 00 28  06 01 00 04
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   03 00 00 08  01 00 00 03  03 00 00 08  03 00 00 02
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   03 00 00 08  02 00 00 01  00 00 00 08  04 00 00 02
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   02 00 00 28  07 01 00 04  03 00 00 08  01 00 00 0c
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   03 00 00 08  03 00 00 02  03 00 00 08  02 00 00 02
>Apr  2 23:53:34 tim-hv4 charon: 09[AUD] DH group MODP_1536_BIT inacceptable, requesting MODP_1024_BIT 
>Apr  2 23:53:34 tim-hv4 pluto[28225]: |   00 00 00 08  04 00 00 0e  02 00 00 28  08 01 00 04
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   03 00 00 08  01 00 00 0c  03 00 00 08  03 00 00 02
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   03 00 00 08  02 00 00 01  00 00 00 08  04 00 00 0e
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   02 00 00 28  09 01 00 04  03 00 00 08  01 00 00 03
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   03 00 00 08  03 00 00 02  03 00 00 08  02 00 00 02
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   00 00 00 08  04 00 00 0e  00 00 00 28  0a 01 00 04
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   03 00 00 08  01 00 00 03  03 00 00 08  03 00 00 02
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   03 00 00 08  02 00 00 01  00 00 00 08  04 00 00 0e
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   28 00 00 c8  00 05 00 00  fe ed a4 74  2e f8 eb 93
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   a1 d9 22 c8  50 42 5c 6d  21 f5 74 f2  86 99 b6 4b
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   98 d3 1a cc  31 71 2f 4e  b0 a9 59 6e  ed 3c 92 e4
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   d8 df 6b 2c  71 91 b0 c1  30 ad da c5  06 a8 1f 7a
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   e6 32 1f 29  f2 82 b9 bf  ab 02 2b a3  b3 93 92 91
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   cc 98 49 79  49 2a c0 c5  ef 1a 7a 3c  2a 2d bf 08
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   c2 93 77 f7  24 05 d0 3a  48 72 2a 48  74 c7 18 51
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   82 cc 07 4a  d3 77 8c 0f  f9 e6 be f1  76 de bf 5c
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   23 a3 cb be  d2 3f 04 d2  df f2 b9 c8  f5 c1 02 b6
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   25 0b 12 2f  4b b6 c2 9f  50 72 dc eb  7f f6 bf 4c
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   95 c0 c6 ad  a5 26 ab 6f  c7 b1 6b 24  e1 da e2 9f
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   6e 95 9c 66  79 ba 94 4c  e4 ee 1a f7  36 83 20 b1
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   29 ff 70 bb  95 df 71 71  2b 80 00 14  15 c5 ba 6c
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   89 9d a2 29  37 38 0b b7  6c 22 c2 60  00 00 00 10
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   4f 45 5a 44  7e 4d 54 7d  6d 41 6e 6c
>Apr  2 23:53:35 tim-hv4 pluto[28225]: | **parse ISAKMP Message:
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |    initiator cookie:
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   b8 54 f1 5d  1b 93 75 ac
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |    responder cookie:
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |   00 00 00 00  00 00 00 00
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_v2SA
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |    ISAKMP version: IKEv2 version 2.0 (rfc4306)
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |    exchange type: ISAKMP_v2_SA_INIT
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |    flags: ISAKMP_FLAG_INIT
>Apr  2 23:53:35 tim-hv4 pluto[28225]: |    message ID:  00 00 00 00
>Apr  2 23:53:36 tim-hv4 pluto[28225]: |    length: 668
>Apr  2 23:53:36 tim-hv4 pluto[28225]: |  processing version=2.0 packet with exchange type=ISAKMP_v2_SA_INIT (34)
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | ICOOKIE:  b8 54 f1 5d  1b 93 75 ac
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | RCOOKIE:  00 00 00 00  00 00 00 00
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | state hash entry 15
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | v2 state object not found
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | ICOOKIE:  b8 54 f1 5d  1b 93 75 ac
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | RCOOKIE:  00 00 00 00  00 00 00 00
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | state hash entry 15
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | v2 state object not found
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | ***parse IKEv2 Security Association Payload:
>Apr  2 23:53:36 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_v2KE
>Apr  2 23:53:36 tim-hv4 pluto[28225]: |    critical bit: Payload-Critical
>Apr  2 23:53:36 tim-hv4 pluto[28225]: |    length: 404
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | processing payload: ISAKMP_NEXT_v2SA (len=404) 
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | ***parse IKEv2 Key Exchange Payload:
>Apr  2 23:53:36 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_v2Ni
>Apr  2 23:53:36 tim-hv4 pluto[28225]: |    length: 200
>Apr  2 23:53:36 tim-hv4 pluto[28225]: |    transform type: 5
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | processing payload: ISAKMP_NEXT_v2KE (len=200) 
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | ***parse IKEv2 Nonce Payload:
>Apr  2 23:53:36 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_v2V
>Apr  2 23:53:36 tim-hv4 pluto[28225]: |    critical bit: Payload-Critical
>Apr  2 23:53:36 tim-hv4 pluto[28225]: |    length: 20
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | processing payload: ISAKMP_NEXT_v2Ni (len=20) 
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | ***parse IKEv2 Vendor ID Payload:
>Apr  2 23:53:36 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_NONE
>Apr  2 23:53:36 tim-hv4 pluto[28225]: |    critical bit: Payload-Non-Critical
>Apr  2 23:53:36 tim-hv4 pluto[28225]: |    length: 16
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | processing payload: ISAKMP_NEXT_v2V (len=16) 
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | find_host_connection called from ikev2parent_inI1outR1, me=9.3.192.210:500 him=9.3.190.198:500 policy=IKEv2ALLOW
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | find_host_pair: comparing to 9.3.192.210:500 9.3.190.198:500 
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | find_host_pair_conn (find_host_connection2): 9.3.192.210:500 9.3.190.198:500 -> hp:i386-ppc 
>Apr  2 23:53:36 tim-hv4 pluto[28225]: | searching for policy=PSK+ENCRYPT+TUNNEL+PFS+!IKEv1+IKEv2ALLOW+IKEv2Init, found=PSK+ENCRYPT+TUNNEL+PFS+!IKEv1+IKEv2ALLOW+IKEv2Init (i386-ppc)
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | find_host_connection returns i386-ppc
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | found connection: i386-ppc 
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | creating state object #1 at 0x8122f20
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | processing connection i386-ppc
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | ICOOKIE:  b8 54 f1 5d  1b 93 75 ac
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | RCOOKIE:  00 00 00 00  00 00 00 00
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | state hash entry 15
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | inserting state object #1 on chain 15
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #1
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | processing connection i386-ppc
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | will not send/process a dcookie
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | 1: w->pcw_dead: 0 w->pcw_work: 0 cnt: 7
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | asking helper 1 to do build_kenonce op on seq: 1 (len=2668, pcw_work=1)
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | crypto helper write of request: cnt=2668<wlen=2668.  
>Apr  2 23:53:37 tim-hv4 pluto[28239]: ! helper 1 read 2664+4/2668 bytesfd: 9
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #1
>Apr  2 23:53:37 tim-hv4 pluto[28239]: ! helper 1 doing build_kenonce op id: 1
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | complete v2 state transition with STF_SUSPEND
>Apr  2 23:53:37 tim-hv4 pluto[28239]: ! Local DH secret:
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | * processed 0 messages from cryptographic helpers 
>Apr  2 23:53:37 tim-hv4 pluto[28239]: !   16 6c f2 68  ae bd fb bf  e1 77 eb 30  fd 0f 6f 6c
>Apr  2 23:53:37 tim-hv4 pluto[28225]: | next event EVENT_PENDING_PHASE2 in 18 seconds
>Apr  2 23:53:37 tim-hv4 pluto[28239]: !   a1 0a f0 d9  a2 7a 3c 07  d0 de 5e 0d  d3 9d b7 52
>Apr  2 23:53:37 tim-hv4 pluto[28239]: ! Public DH value sent:
>Apr  2 23:53:37 tim-hv4 pluto[28239]: !   6e 35 f2 fb  98 23 79 48  a2 90 ce 83  d8 69 21 61
>Apr  2 23:53:37 tim-hv4 pluto[28239]: !   fc 71 b5 f1  92 51 46 66  5f f5 80 4a  4f 4a 37 2f
>Apr  2 23:53:37 tim-hv4 pluto[28239]: !   82 7b 7d c6  a6 ca d1 90  7e 8c 29 82  53 6a 58 08
>Apr  2 23:53:37 tim-hv4 pluto[28239]: !   46 dd 56 e7  e9 c9 3e ac  0f 8b 08 6a  20 af 5c 36
>Apr  2 23:53:37 tim-hv4 pluto[28239]: !   37 73 41 e2  46 8c ba ef  bb 34 95 ff  f5 db 32 2a
>Apr  2 23:53:37 tim-hv4 pluto[28239]: !   c9 4b 3f 3e  4e 06 41 d8  06 52 16 db  cf f7 e4 d7
>Apr  2 23:53:37 tim-hv4 pluto[28239]: !   9d 95 6f 35  d0 28 24 d6  6d f0 0f 5e  03 95 f9 51
>Apr  2 23:53:37 tim-hv4 pluto[28239]: !   35 a9 12 1d  4e 9e c9 eb  56 fc 6a 76  34 32 02 c7
>Apr  2 23:53:37 tim-hv4 pluto[28239]: !   d5 65 12 3a  aa 0b 2f 84  d1 79 07 b0  4f 37 0e 6e
>Apr  2 23:53:37 tim-hv4 pluto[28239]: !   84 ac 43 8d  2e bc 9d f7  e1 e0 ee 34  93 5f 40 66
>Apr  2 23:53:37 tim-hv4 pluto[28239]: !   63 78 14 23  5f a0 85 9b  ae 5e 8b 98  a6 23 28 7c
>Apr  2 23:53:38 tim-hv4 pluto[28239]: !   32 f4 0f c1  a5 87 0f 27  76 14 66 0a  76 49 4d 0d
>Apr  2 23:53:38 tim-hv4 pluto[28239]: ! Generated nonce:
>Apr  2 23:53:38 tim-hv4 pluto[28239]: !   a1 2c 68 f3  c2 09 c3 b8  20 af f7 85  2d 75 6b 45
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |  
>Apr  2 23:53:38 tim-hv4 pluto[28225]: | helper 1 has finished work (cnt now 1)
>Apr  2 23:53:38 tim-hv4 pluto[28225]: | helper 1 replies to id: q#1
>Apr  2 23:53:38 tim-hv4 pluto[28225]: | calling callback function 0x8042770
>Apr  2 23:53:38 tim-hv4 pluto[28225]: | ikev2 parent inI1outR1: calculated ke+nonce, sending R1
>Apr  2 23:53:38 tim-hv4 pluto[28225]: | processing connection i386-ppc
>Apr  2 23:53:38 tim-hv4 pluto[28225]: | **emit ISAKMP Message:
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    initiator cookie:
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |   b8 54 f1 5d  1b 93 75 ac
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    responder cookie:
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |   bb 3c 8e 45  5c e3 20 af
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_v2SA
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    ISAKMP version: IKEv2 version 2.0 (rfc4306)
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    exchange type: ISAKMP_v2_SA_INIT
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    flags: ISAKMP_FLAG_RESPONSE
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    message ID:  00 00 00 00
>Apr  2 23:53:38 tim-hv4 pluto[28225]: | ***emit IKEv2 Security Association Payload:
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_v2KE
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    critical bit: Payload-Critical
>Apr  2 23:53:38 tim-hv4 pluto[28225]: | no IKE algorithms for this connection 
>Apr  2 23:53:38 tim-hv4 pluto[28225]: | ****parse IKEv2 Proposal Substructure Payload:
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_P
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    length: 40
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    prop #: 1
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    proto ID: 1
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    spi size: 0
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    # transforms: 4
>Apr  2 23:53:38 tim-hv4 pluto[28225]: | *****parse IKEv2 Transform Substructure Payload:
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_T
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    length: 8
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    transform type: 1
>Apr  2 23:53:38 tim-hv4 pluto[28225]: |    transform ID: 12
>Apr  2 23:53:39 tim-hv4 pluto[28225]: | *****parse IKEv2 Transform Substructure Payload:
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_T
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    length: 8
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    transform type: 3
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    transform ID: 2
>Apr  2 23:53:39 tim-hv4 pluto[28225]: | *****parse IKEv2 Transform Substructure Payload:
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_T
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    length: 8
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    transform type: 2
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    transform ID: 2
>Apr  2 23:53:39 tim-hv4 pluto[28225]: | *****parse IKEv2 Transform Substructure Payload:
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_NONE
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    length: 8
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    transform type: 4
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    transform ID: 5
>Apr  2 23:53:39 tim-hv4 pluto[28225]: | ****parse IKEv2 Proposal Substructure Payload:
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_P
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    length: 40
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    prop #: 2
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    proto ID: 1
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    spi size: 0
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    # transforms: 4
>Apr  2 23:53:39 tim-hv4 pluto[28225]: | ****emit IKEv2 Proposal Substructure Payload:
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_NONE
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    prop #: 1
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    proto ID: 1
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    spi size: 0
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    # transforms: 4
>Apr  2 23:53:39 tim-hv4 pluto[28225]: | *****emit IKEv2 Transform Substructure Payload:
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_T
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    transform type: 1
>Apr  2 23:53:39 tim-hv4 pluto[28225]: |    transform ID: 12
>Apr  2 23:53:39 tim-hv4 pluto[28225]: | emitting length of IKEv2 Transform Substructure Payload: 8
>Apr  2 23:53:39 tim-hv4 pluto[28225]: | *****emit IKEv2 Transform Substructure Payload:
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_T
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |    transform type: 3
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |    transform ID: 2
>Apr  2 23:53:40 tim-hv4 pluto[28225]: | emitting length of IKEv2 Transform Substructure Payload: 8
>Apr  2 23:53:40 tim-hv4 pluto[28225]: | *****emit IKEv2 Transform Substructure Payload:
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_T
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |    transform type: 2
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |    transform ID: 2
>Apr  2 23:53:40 tim-hv4 pluto[28225]: | emitting length of IKEv2 Transform Substructure Payload: 8
>Apr  2 23:53:40 tim-hv4 pluto[28225]: | *****emit IKEv2 Transform Substructure Payload:
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_NONE
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |    transform type: 4
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |    transform ID: 5
>Apr  2 23:53:40 tim-hv4 pluto[28225]: | emitting length of IKEv2 Transform Substructure Payload: 8
>Apr  2 23:53:40 tim-hv4 pluto[28225]: | emitting length of IKEv2 Proposal Substructure Payload: 40
>Apr  2 23:53:40 tim-hv4 pluto[28225]: | emitting length of IKEv2 Security Association Payload: 44
>Apr  2 23:53:40 tim-hv4 pluto[28225]: | DH public value received:
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |   fe ed a4 74  2e f8 eb 93  a1 d9 22 c8  50 42 5c 6d
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |   21 f5 74 f2  86 99 b6 4b  98 d3 1a cc  31 71 2f 4e
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |   b0 a9 59 6e  ed 3c 92 e4  d8 df 6b 2c  71 91 b0 c1
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |   30 ad da c5  06 a8 1f 7a  e6 32 1f 29  f2 82 b9 bf
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |   ab 02 2b a3  b3 93 92 91  cc 98 49 79  49 2a c0 c5
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |   ef 1a 7a 3c  2a 2d bf 08  c2 93 77 f7  24 05 d0 3a
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |   48 72 2a 48  74 c7 18 51  82 cc 07 4a  d3 77 8c 0f
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |   f9 e6 be f1  76 de bf 5c  23 a3 cb be  d2 3f 04 d2
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |   df f2 b9 c8  f5 c1 02 b6  25 0b 12 2f  4b b6 c2 9f
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |   50 72 dc eb  7f f6 bf 4c  95 c0 c6 ad  a5 26 ab 6f
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |   c7 b1 6b 24  e1 da e2 9f  6e 95 9c 66  79 ba 94 4c
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |   e4 ee 1a f7  36 83 20 b1  29 ff 70 bb  95 df 71 71
>Apr  2 23:53:40 tim-hv4 pluto[28225]: | ***emit IKEv2 Key Exchange Payload:
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_v2Ni
>Apr  2 23:53:40 tim-hv4 pluto[28225]: |    transform type: 5
>Apr  2 23:53:40 tim-hv4 pluto[28225]: | emitting 192 raw bytes of ikev2 g^x into IKEv2 Key Exchange Payload
>Apr  2 23:53:40 tim-hv4 pluto[28225]: | ikev2 g^x  6e 35 f2 fb  98 23 79 48  a2 90 ce 83  d8 69 21 61
>Apr  2 23:53:40 tim-hv4 pluto[28225]: | ikev2 g^x  fc 71 b5 f1  92 51 46 66  5f f5 80 4a  4f 4a 37 2f
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | ikev2 g^x  82 7b 7d c6  a6 ca d1 90  7e 8c 29 82  53 6a 58 08
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | ikev2 g^x  46 dd 56 e7  e9 c9 3e ac  0f 8b 08 6a  20 af 5c 36
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | ikev2 g^x  37 73 41 e2  46 8c ba ef  bb 34 95 ff  f5 db 32 2a
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | ikev2 g^x  c9 4b 3f 3e  4e 06 41 d8  06 52 16 db  cf f7 e4 d7
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | ikev2 g^x  9d 95 6f 35  d0 28 24 d6  6d f0 0f 5e  03 95 f9 51
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | ikev2 g^x  35 a9 12 1d  4e 9e c9 eb  56 fc 6a 76  34 32 02 c7
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | ikev2 g^x  d5 65 12 3a  aa 0b 2f 84  d1 79 07 b0  4f 37 0e 6e
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | ikev2 g^x  84 ac 43 8d  2e bc 9d f7  e1 e0 ee 34  93 5f 40 66
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | ikev2 g^x  63 78 14 23  5f a0 85 9b  ae 5e 8b 98  a6 23 28 7c
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | ikev2 g^x  32 f4 0f c1  a5 87 0f 27  76 14 66 0a  76 49 4d 0d
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | emitting length of IKEv2 Key Exchange Payload: 200
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | ***emit IKEv2 Nonce Payload:
>Apr  2 23:53:41 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_v2V
>Apr  2 23:53:41 tim-hv4 pluto[28225]: |    critical bit: Payload-Critical
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | emitting 16 raw bytes of IKEv2 nonce into IKEv2 Nonce Payload
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | IKEv2 nonce  a1 2c 68 f3  c2 09 c3 b8  20 af f7 85  2d 75 6b 45
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | emitting length of IKEv2 Nonce Payload: 20
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | ***emit ISAKMP Vendor ID Payload:
>Apr  2 23:53:41 tim-hv4 pluto[28225]: |    next payload type: ISAKMP_NEXT_NONE
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | emitting 12 raw bytes of Vendor ID into ISAKMP Vendor ID Payload
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | Vendor ID  4f 45 5a 44  7e 4d 54 7d  6d 41 6e 6c
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | emitting length of ISAKMP Vendor ID Payload: 16
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | emitting length of ISAKMP Message: 308
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | complete v2 state transition with STF_OK
>Apr  2 23:53:41 tim-hv4 pluto[28225]: "i386-ppc" #1: transition from state STATE_IKEv2_START to state STATE_PARENT_R1
>Apr  2 23:53:41 tim-hv4 pluto[28225]: "i386-ppc" #1: STATE_PARENT_R1: received v2I1, sent v2R1 {auth=IKEv2 cipher=aes_128 integ=sha1 prf=oakley_sha group=modp1536}
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | sending reply packet to 9.3.190.198:500 (from port 500)
>Apr  2 23:53:41 tim-hv4 pluto[28225]: | sending 308 bytes for STATE_IKEv2_START through eth0:500 to 9.3.190.198:500 (using #1)
>Apr  2 23:53:41 tim-hv4 pluto[28225]: |   b8 54 f1 5d  1b 93 75 ac  bb 3c 8e 45  5c e3 20 af
>Apr  2 23:53:41 tim-hv4 pluto[28225]: |   21 20 22 20  00 00 00 00  00 00 01 34  22 80 00 2c
>Apr  2 23:53:41 tim-hv4 pluto[28225]: |   00 00 00 28  01 01 00 04  03 00 00 08  01 00 00 0c
>Apr  2 23:53:41 tim-hv4 pluto[28225]: |   03 00 00 08  03 00 00 02  03 00 00 08  02 00 00 02
>Apr  2 23:53:41 tim-hv4 pluto[28225]: |   00 00 00 08  04 00 00 05  28 00 00 c8  00 05 00 00
>Apr  2 23:53:41 tim-hv4 pluto[28225]: |   6e 35 f2 fb  98 23 79 48  a2 90 ce 83  d8 69 21 61
>Apr  2 23:53:41 tim-hv4 pluto[28225]: |   fc 71 b5 f1  92 51 46 66  5f f5 80 4a  4f 4a 37 2f
>Apr  2 23:53:41 tim-hv4 pluto[28225]: |   82 7b 7d c6  a6 ca d1 90  7e 8c 29 82  53 6a 58 08
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   46 dd 56 e7  e9 c9 3e ac  0f 8b 08 6a  20 af 5c 36
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   37 73 41 e2  46 8c ba ef  bb 34 95 ff  f5 db 32 2a
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   c9 4b 3f 3e  4e 06 41 d8  06 52 16 db  cf f7 e4 d7
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   9d 95 6f 35  d0 28 24 d6  6d f0 0f 5e  03 95 f9 51
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   35 a9 12 1d  4e 9e c9 eb  56 fc 6a 76  34 32 02 c7
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   d5 65 12 3a  aa 0b 2f 84  d1 79 07 b0  4f 37 0e 6e
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   84 ac 43 8d  2e bc 9d f7  e1 e0 ee 34  93 5f 40 66
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   63 78 14 23  5f a0 85 9b  ae 5e 8b 98  a6 23 28 7c
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   32 f4 0f c1  a5 87 0f 27  76 14 66 0a  76 49 4d 0d
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   2b 80 00 14  a1 2c 68 f3  c2 09 c3 b8  20 af f7 85
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   2d 75 6b 45  00 00 00 10  4f 45 5a 44  7e 4d 54 7d
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   6d 41 6e 6c
>Apr  2 23:53:42 tim-hv4 pluto[28225]: | * processed 1 messages from cryptographic helpers 
>Apr  2 23:53:42 tim-hv4 pluto[28225]: | next event EVENT_PENDING_PHASE2 in 13 seconds
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |  
>Apr  2 23:53:42 tim-hv4 pluto[28225]: | rejected packet:
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   b8 54 f1 5d  1b 93 75 ac  bb 3c 8e 45  5c e3 20 af
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   21 20 22 20  00 00 00 00  00 00 01 34  22 80 00 2c
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   00 00 00 28  01 01 00 04  03 00 00 08  01 00 00 0c
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   03 00 00 08  03 00 00 02  03 00 00 08  02 00 00 02
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   00 00 00 08  04 00 00 05  28 00 00 c8  00 05 00 00
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   6e 35 f2 fb  98 23 79 48  a2 90 ce 83  d8 69 21 61
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   fc 71 b5 f1  92 51 46 66  5f f5 80 4a  4f 4a 37 2f
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   82 7b 7d c6  a6 ca d1 90  7e 8c 29 82  53 6a 58 08
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   46 dd 56 e7  e9 c9 3e ac  0f 8b 08 6a  20 af 5c 36
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   37 73 41 e2  46 8c ba ef  bb 34 95 ff  f5 db 32 2a
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   c9 4b 3f 3e  4e 06 41 d8  06 52 16 db  cf f7 e4 d7
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   9d 95 6f 35  d0 28 24 d6  6d f0 0f 5e  03 95 f9 51
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   35 a9 12 1d  4e 9e c9 eb  56 fc 6a 76  34 32 02 c7
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   d5 65 12 3a  aa 0b 2f 84  d1 79 07 b0  4f 37 0e 6e
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   84 ac 43 8d  2e bc 9d f7  e1 e0 ee 34  93 5f 40 66
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   63 78 14 23  5f a0 85 9b  ae 5e 8b 98  a6 23 28 7c
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   32 f4 0f c1  a5 87 0f 27  76 14 66 0a  76 49 4d 0d
>Apr  2 23:53:42 tim-hv4 pluto[28225]: |   2b 80 00 14  a1 2c 68 f3  c2 09 c3 b8  20 af f7 85
>Apr  2 23:53:43 tim-hv4 pluto[28225]: |   2d 75 6b 45  00 00 00 10  4f 45 5a 44  7e 4d 54 7d
>Apr  2 23:53:43 tim-hv4 pluto[28225]: |   6d 41 6e 6c
>Apr  2 23:53:43 tim-hv4 pluto[28225]: | control:
>Apr  2 23:53:43 tim-hv4 pluto[28225]: |   00 00 00 18  00 00 00 00  00 00 00 08  00 00 00 02
>Apr  2 23:53:43 tim-hv4 pluto[28225]: |   09 03 c0 d2  09 03 c0 d2  00 00 00 2c  00 00 00 00
>Apr  2 23:53:43 tim-hv4 pluto[28225]: |   00 00 00 0b  00 00 00 6f  02 03 03 00  00 00 00 00
>Apr  2 23:53:43 tim-hv4 pluto[28225]: |   00 00 00 00  00 02 00 00  09 03 be c6  00 00 00 00
>Apr  2 23:53:43 tim-hv4 pluto[28225]: |   00 00 00 00
>Apr  2 23:53:43 tim-hv4 pluto[28225]: | name:
>Apr  2 23:53:43 tim-hv4 pluto[28225]: |   00 02 01 f4  09 03 be c6  00 00 00 00  00 00 00 00
>Apr  2 23:53:43 tim-hv4 pluto[28225]: "i386-ppc" #1: ERROR: asynchronous network error report on eth0 (sport=500) for message to 9.3.190.198 port 500, complainant 9.3.190.198: Connection refused [errno 111, origin ICMP type 3 code 3 (not authenticated)]
>Apr  2 23:53:43 tim-hv4 pluto[28225]: | * processed 0 messages from cryptographic helpers 
>Apr  2 23:53:43 tim-hv4 pluto[28225]: | next event EVENT_PENDING_PHASE2 in 12 seconds
>Apr  2 23:53:55 tim-hv4 pluto[28225]: |  
>Apr  2 23:53:55 tim-hv4 pluto[28225]: | *time to handle event
>Apr  2 23:53:55 tim-hv4 pluto[28225]: | handling event EVENT_PENDING_PHASE2
>Apr  2 23:53:55 tim-hv4 pluto[28225]: | event after this is EVENT_LOG_DAILY in 365 seconds
>Apr  2 23:53:55 tim-hv4 pluto[28225]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>Apr  2 23:53:55 tim-hv4 pluto[28225]: | pending review: connection "i386-ppc" was not up, skipped
>Apr  2 23:53:55 tim-hv4 pluto[28225]: | next event EVENT_PENDING_PHASE2 in 120 seconds
>Apr  2 23:55:55 tim-hv4 pluto[28225]: |  
>Apr  2 23:55:55 tim-hv4 pluto[28225]: | *time to handle event
>Apr  2 23:55:55 tim-hv4 pluto[28225]: | handling event EVENT_PENDING_PHASE2
>Apr  2 23:55:55 tim-hv4 pluto[28225]: | event after this is EVENT_LOG_DAILY in 245 seconds
>Apr  2 23:55:55 tim-hv4 pluto[28225]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>Apr  2 23:55:55 tim-hv4 pluto[28225]: | pending review: connection "i386-ppc" was not up, skipped
>Apr  2 23:55:55 tim-hv4 pluto[28225]: | next event EVENT_PENDING_PHASE2 in 120 seconds
>Apr  2 23:57:55 tim-hv4 pluto[28225]: |  
>Apr  2 23:57:55 tim-hv4 pluto[28225]: | *time to handle event
>Apr  2 23:57:55 tim-hv4 pluto[28225]: | handling event EVENT_PENDING_PHASE2
>Apr  2 23:57:55 tim-hv4 pluto[28225]: | event after this is EVENT_LOG_DAILY in 125 seconds
>Apr  2 23:57:55 tim-hv4 pluto[28225]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>Apr  2 23:57:55 tim-hv4 pluto[28225]: | pending review: connection "i386-ppc" was not up, skipped
>Apr  2 23:57:55 tim-hv4 pluto[28225]: | next event EVENT_PENDING_PHASE2 in 120 seconds
>Apr  2 23:59:55 tim-hv4 pluto[28225]: |  
>Apr  2 23:59:55 tim-hv4 pluto[28225]: | *time to handle event
>Apr  2 23:59:55 tim-hv4 pluto[28225]: | handling event EVENT_PENDING_PHASE2
>Apr  2 23:59:55 tim-hv4 pluto[28225]: | event after this is EVENT_LOG_DAILY in 5 seconds
>Apr  2 23:59:55 tim-hv4 pluto[28225]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>Apr  2 23:59:55 tim-hv4 pluto[28225]: | pending review: connection "i386-ppc" was not up, skipped
>Apr  2 23:59:55 tim-hv4 pluto[28225]: | next event EVENT_LOG_DAILY in 5 seconds
>Apr  3 00:00:00 tim-hv4 pluto[28225]: |  
>Apr  3 00:00:00 tim-hv4 pluto[28225]: | *time to handle event
>Apr  3 00:00:00 tim-hv4 pluto[28225]: | handling event EVENT_LOG_DAILY
>Apr  3 00:00:00 tim-hv4 pluto[28225]: | event after this is EVENT_PENDING_PHASE2 in 115 seconds
>Apr  3 00:00:00 tim-hv4 pluto[28225]: | inserting event EVENT_LOG_DAILY, timeout in 86400 seconds
>Apr  3 00:00:00 tim-hv4 pluto[28225]: | next event EVENT_PENDING_PHASE2 in 115 seconds
>Apr  3 00:01:55 tim-hv4 pluto[28225]: |  
>Apr  3 00:01:55 tim-hv4 pluto[28225]: | *time to handle event
>Apr  3 00:01:55 tim-hv4 pluto[28225]: | handling event EVENT_PENDING_PHASE2
>Apr  3 00:01:55 tim-hv4 pluto[28225]: | event after this is EVENT_REINIT_SECRET in 2640 seconds
>Apr  3 00:01:55 tim-hv4 pluto[28225]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>Apr  3 00:01:55 tim-hv4 pluto[28225]: | pending review: connection "i386-ppc" was not up, skipped
>Apr  3 00:01:55 tim-hv4 pluto[28225]: | next event EVENT_PENDING_PHASE2 in 120 seconds
>Apr  3 00:03:55 tim-hv4 pluto[28225]: |  
>Apr  3 00:03:55 tim-hv4 pluto[28225]: | *time to handle event
>Apr  3 00:03:55 tim-hv4 pluto[28225]: | handling event EVENT_PENDING_PHASE2
>Apr  3 00:03:55 tim-hv4 pluto[28225]: | event after this is EVENT_REINIT_SECRET in 2520 seconds
>Apr  3 00:03:55 tim-hv4 pluto[28225]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>Apr  3 00:03:55 tim-hv4 pluto[28225]: | pending review: connection "i386-ppc" was not up, skipped
>Apr  3 00:03:55 tim-hv4 pluto[28225]: | next event EVENT_PENDING_PHASE2 in 120 seconds
>Apr  3 00:05:55 tim-hv4 pluto[28225]: |  
>Apr  3 00:05:55 tim-hv4 pluto[28225]: | *time to handle event
>Apr  3 00:05:55 tim-hv4 pluto[28225]: | handling event EVENT_PENDING_PHASE2
>Apr  3 00:05:55 tim-hv4 pluto[28225]: | event after this is EVENT_REINIT_SECRET in 2400 seconds
>Apr  3 00:05:55 tim-hv4 pluto[28225]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>Apr  3 00:05:55 tim-hv4 pluto[28225]: | pending review: connection "i386-ppc" was not up, skipped
>Apr  3 00:05:55 tim-hv4 pluto[28225]: | next event EVENT_PENDING_PHASE2 in 120 seconds

Actions: View

Attachments on bug 438826: 299030 | 299031 | 299289 | 299290 | 299492 | 299493 | 299510 | 300144 | 300178 | 300179