Attachment 950892 Details for Bug 1157379 – pluto.log

pluto.log

pluto.log (text/plain), 102.53 KB, created by Hangbin Liu on 2014-10-27 06:50:24 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Hangbin Liu

Created: 2014-10-27 06:50:24 UTC

Size: 102.53 KB

patch

obsolete

>nss directory plutomain: /etc/ipsec.d
>NSS Initialized
>libcap-ng support [enabled]
>FIPS HMAC integrity verification test passed
>FIPS: pluto daemon NOT running in FIPS mode
>Linux audit support [disabled]
>Starting Pluto (Libreswan Version 3.10 XFRM(netkey) KLIPS NSS DNSSEC FIPS_CHECK LABELED_IPSEC LIBCAP_NG XAUTH_PAM NETWORKMANAGER KLIPS_MAST CURL(non-NSS) LDAP(non-NSS)) pid:10771
>core dump dir: /var/run/pluto
>secrets file: /etc/ipsec.secrets
>leak-detective disabled
>SAref support [disabled]: Protocol not available
>SAbind support [disabled]: Protocol not available
>NSS crypto [enabled]
>XAUTH PAM support [enabled]
>   NAT-Traversal support  [enabled]
>| inserting event EVENT_REINIT_SECRET, timeout in 3600 seconds
>| event added at head of queue
>| inserting event EVENT_PENDING_DDNS, timeout in 60 seconds
>| event added at head of queue
>| inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
>| event added after event EVENT_PENDING_DDNS
>ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC_SSH: Ok (ret=0)
>ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC: Ok (ret=0)
>ike_alg_register_enc(): Activating OAKLEY_SERPENT_CBC: Ok (ret=0)
>ike_alg_register_enc(): Activating OAKLEY_AES_CBC: Ok (ret=0)
>ike_alg_register_hash(): Activating OAKLEY_SHA2_512: Ok (ret=0)
>ike_alg_register_hash(): Activating OAKLEY_SHA2_384: Ok (ret=0)
>ike_alg_register_hash(): Activating OAKLEY_SHA2_256: Ok (ret=0)
>starting up 3 crypto helpers
>started thread for crypto helper 0 (master fd 7)
>| status value returned by setting the priority of this thread (crypto helper 0) 22
>| crypto helper 0 waiting on fd 8
>| status value returned by setting the priority of this thread (crypto helper 1) 22
>| crypto helper 1 waiting on fd 10
>started thread for crypto helper 1 (master fd 9)
>started thread for crypto helper 2 (master fd 11)
>| status value returned by setting the priority of this thread (crypto helper 2) 22
>| crypto helper 2 waiting on fd 13
>Using Linux XFRM/NETKEY IPsec interface code on 3.10.0-188.el7.x86_64
>| process 10771 listening for PF_KEY_V2 on file descriptor 16
>| finish_pfkey_msg: K_SADB_REGISTER message 1 for AH 
>|   02 07 00 02  02 00 00 00  01 00 00 00  13 2a 00 00
>| pfkey_get: K_SADB_REGISTER message 1
>| AH registered with kernel.
>| finish_pfkey_msg: K_SADB_REGISTER message 2 for ESP 
>|   02 07 00 03  02 00 00 00  02 00 00 00  13 2a 00 00
>| pfkey_get: K_SADB_REGISTER message 2
>| kernel_alg_init(): memset(0x7f25698ae840, 0, 2048) memset(0x7f25698af040, 0, 2048)
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: sadb_msg_len=22 sadb_supported_len=72
>| kernel_alg_add(): satype=3, exttype=14, alg_id=251(ESP_KAME_NULL)
>| 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
>| kernel_alg_add(): satype=3, exttype=14, alg_id=2(ESP_DES)
>| 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
>| kernel_alg_add(): satype=3, exttype=14, alg_id=3(ESP_3DES)
>| 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
>| kernel_alg_add(): satype=3, exttype=14, alg_id=5(ESP_IDEA)
>| 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
>| kernel_alg_add(): satype=3, exttype=14, alg_id=6(ESP_CAST)
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[4], exttype=14, satype=3, alg_id=6, alg_ivlen=0, alg_minbits=384, alg_maxbits=384, res=0, ret=1
>| kernel_alg_add(): satype=3, exttype=14, alg_id=7(ESP_BLOWFISH)
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[5], exttype=14, satype=3, alg_id=7, alg_ivlen=0, alg_minbits=512, alg_maxbits=512, res=0, ret=1
>| kernel_alg_add(): satype=3, exttype=14, alg_id=8(ESP_3IDEA)
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[6], exttype=14, satype=3, alg_id=8, alg_ivlen=0, alg_minbits=160, alg_maxbits=160, res=0, ret=1
>| kernel_alg_add(): satype=3, exttype=14, alg_id=9(ESP_DES_IV32)
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[7], exttype=14, satype=3, alg_id=9, alg_ivlen=0, alg_minbits=128, alg_maxbits=128, res=0, ret=1
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: sadb_msg_len=22 sadb_supported_len=88
>| kernel_alg_add(): satype=3, exttype=15, alg_id=11(ESP_NULL)
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[8], exttype=15, satype=3, alg_id=11, alg_ivlen=0, alg_minbits=0, alg_maxbits=0, res=0, ret=1
>| kernel_alg_add(): satype=3, exttype=15, alg_id=2(ESP_DES)
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[9], exttype=15, satype=3, alg_id=2, alg_ivlen=8, alg_minbits=64, alg_maxbits=64, res=0, ret=1
>| kernel_alg_add(): satype=3, exttype=15, alg_id=3(ESP_3DES)
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[10], exttype=15, satype=3, alg_id=3, alg_ivlen=8, alg_minbits=192, alg_maxbits=192, res=0, ret=1
>| kernel_alg_add(): satype=3, exttype=15, alg_id=6(ESP_CAST)
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[11], exttype=15, satype=3, alg_id=6, alg_ivlen=8, alg_minbits=40, alg_maxbits=128, res=0, ret=1
>| kernel_alg_add(): satype=3, exttype=15, alg_id=7(ESP_BLOWFISH)
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[12], exttype=15, satype=3, alg_id=7, alg_ivlen=8, alg_minbits=40, alg_maxbits=448, res=0, ret=1
>| kernel_alg_add(): satype=3, exttype=15, alg_id=12(ESP_AES)
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[13], exttype=15, satype=3, alg_id=12, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
>| kernel_alg_add(): satype=3, exttype=15, alg_id=252(ESP_SERPENT)
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[14], exttype=15, satype=3, alg_id=252, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
>| kernel_alg_add(): satype=3, exttype=15, alg_id=22(ESP_CAMELLIA)
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[15], exttype=15, satype=3, alg_id=22, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
>| kernel_alg_add(): satype=3, exttype=15, alg_id=253(ESP_TWOFISH)
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[16], exttype=15, satype=3, alg_id=253, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
>| kernel_alg_add(): satype=3, exttype=15, alg_id=13(ESP_AES_CTR)
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[17], exttype=15, satype=3, alg_id=13, alg_ivlen=8, alg_minbits=160, alg_maxbits=288, res=0, ret=1
>| kernel_alg_add(): satype=3, exttype=15, alg_id=18(ESP_AES_GCM_A)
>| kernel_alg_add(): satype=3, exttype=15, alg_id=19(ESP_AES_GCM_B)
>| kernel_alg_add(): satype=3, exttype=15, alg_id=20(ESP_AES_GCM_C)
>| kernel_alg_add(): satype=3, exttype=15, alg_id=14(ESP_AES_CCM_A)
>| kernel_alg_add(): satype=3, exttype=15, alg_id=15(ESP_AES_CCM_B)
>| kernel_alg_add(): satype=3, exttype=15, alg_id=16(ESP_AES_CCM_C)
>ike_alg_register_enc(): Activating aes_ccm_8: Ok (ret=0)
>Warning: failed to register algo_aes_ccm_8 for IKE
>ike_alg_register_enc(): Activating aes_ccm_12: Ok (ret=0)
>Warning: failed to register algo_aes_ccm_12 for IKE
>ike_alg_register_enc(): Activating aes_ccm_16: Ok (ret=0)
>Warning: failed to register algo_aes_ccm_16 for IKE
>ike_alg_register_enc(): Activating aes_gcm_8: Ok (ret=0)
>Warning: failed to register algo_aes_gcm_8 for IKE
>ike_alg_register_enc(): Activating aes_gcm_12: Ok (ret=0)
>Warning: failed to register algo_aes_gcm_12 for IKE
>ike_alg_register_enc(): Activating aes_gcm_16: Ok (ret=0)
>Warning: failed to register algo_aes_gcm_16 for IKE
>| Registered AEAD AES CCM/GCM algorithms
>| ESP registered with kernel.
>| finish_pfkey_msg: K_SADB_REGISTER message 3 for IPCOMP 
>|   02 07 00 09  02 00 00 00  03 00 00 00  13 2a 00 00
>| pfkey_get: K_SADB_REGISTER message 3
>| IPCOMP registered with kernel.
>| Registered AH, ESP and IPCOMP
>| Changed path to directory '/etc/ipsec.d/cacerts'
>| Changing to directory '/etc/ipsec.d/crls'
>| selinux support is enabled. 
>| inserting event EVENT_LOG_DAILY, timeout in 34172 seconds
>| event added after event EVENT_REINIT_SECRET
>| next event EVENT_PENDING_DDNS in 60 seconds
>| calling addconn helper using execve
>|  
>| *received whack message
>| entering aalg_getbyname_ike()
>| raw_alg_info_ike_add() ealg=5 aalg=2 modp_id=2, cnt=1
>| Added new connection ikev2 with policy PSK+ENCRYPT+PFS+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW
>| from whack: got --esp=3des-sha1
>| esp string values: 3DES(3)_000-SHA1(2)_000
>| ike (phase1) algorithm values: 3DES_CBC(5)_000-SHA1(2)_000-MODP1024(2)
>| counting wild cards for 2001:db8:1:1::1234 is 0
>| counting wild cards for 2001:db8:f:1::1 is 0
>added connection description "ikev2"
>| 2001:db8:1:1::1234<2001:0db8:0001:0001::1234>...2001:db8:f:1::1<2001:0db8:000f:0001::1>
>| ike_life: 3600s; ipsec_life: 28800s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0; policy: PSK+ENCRYPT+PFS+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_PENDING_DDNS in 59 seconds
>| next event EVENT_PENDING_DDNS in 59 seconds
>|  
>| *received whack message
>listening for IKE messages
>| Inspecting interface lo 
>| found lo with address 127.0.0.1
>| Inspecting interface p7p1 
>| found p7p1 with address 10.66.13.22
>adding interface p7p1/p7p1 10.66.13.22:500
>| NAT-Traversal: Trying new style NAT-T
>| NAT-Traversal: ESPINUDP(2) setup failed for new style NAT-T family IPv4 (errno=19)
>| NAT-Traversal: Trying old style NAT-T
>| NAT-Traversal: ESPINUDP(2) setup succeeded for old style NAT-T family IPv4
>adding interface p7p1/p7p1 10.66.13.22:4500
>adding interface lo/lo 127.0.0.1:500
>| NAT-Traversal: Trying new style NAT-T
>| NAT-Traversal: ESPINUDP(2) setup failed for new style NAT-T family IPv4 (errno=19)
>| NAT-Traversal: Trying old style NAT-T
>| NAT-Traversal: ESPINUDP(2) setup succeeded for old style NAT-T family IPv4
>adding interface lo/lo 127.0.0.1:4500
>| found lo with address 0000:0000:0000:0000:0000:0000:0000:0001
>| found p6p1 with address 2001:0db8:0001:0001:0000:0000:0000:1234
>adding interface p6p1/p6p1 2001:db8:1:1::1234:500
>adding interface lo/lo ::1:500
>| connect_to_host_pair: 2001:db8:1:1::1234:500 2001:db8:f:1::1:500 -> hp:none 
>| certs and keys locked by 'free_preshared_secrets'
>| certs and keys unlocked by 'free_preshard_secrets'
>loading secrets from "/etc/ipsec.secrets"
>| id type added to secret(0x7f256afb9f20) PPK_PSK: %any
>| id type added to secret(0x7f256afb9f20) PPK_PSK: %any
>| Processing PSK at line 1: passed
>| certs and keys locked by 'process_secret'
>| certs and keys unlocked by 'process_secret'
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_PENDING_DDNS in 59 seconds
>| next event EVENT_PENDING_DDNS in 59 seconds
>|  
>| *received whack message
>| processing connection ikev2
>| kernel_alg_db_new() initial trans_cnt=128
>| kernel_alg_db_new() will return p_new->protoid=3, p_new->trans_cnt=1
>| kernel_alg_db_new()     trans[0]: transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=2
>| returning new proposal from esp_info
>| creating state object #1 at 0x7f256afba0b0
>| processing connection ikev2
>| ICOOKIE:  a5 6c 9f 5e  29 9d e7 03
>| RCOOKIE:  00 00 00 00  00 00 00 00
>| state hash entry 6
>| inserting state object #1
>| inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #1
>| event added at head of queue
>| processing connection ikev2
>| Queuing pending Quick Mode with 2001:db8:f:1::1 "ikev2"
>"ikev2" #1: initiating v2 parent SA
>| crypto helper 0: pcw_work: 0
>| asking crypto helper 0 to do build_kenonce; request ID 1 (len=2768, pcw_work=0)
>| #1 send_crypto_helper_request:519 st->st_calculating = TRUE;
>| deleting event for #1
>| inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #1
>| event added after event EVENT_PENDING_PHASE2
>| crypto helper 0 read fd: 8
>| crypto helper 0 doing build_kenonce; request ID 1
>| NSS: Value of Prime:
>|   ff ff ff ff  ff ff ff ff  c9 0f da a2  21 68 c2 34
>|   c4 c6 62 8b  80 dc 1c d1  29 02 4e 08  8a 67 cc 74
>|   02 0b be a6  3b 13 9b 22  51 4a 08 79  8e 34 04 dd
>|   ef 95 19 b3  cd 3a 43 1b  30 2b 0a 6d  f2 5f 14 37
>|   4f e1 35 6d  6d 51 c2 45  e4 85 b5 76  62 5e 7e c6
>|   f4 4c 42 e9  a6 37 ed 6b  0b ff 5c b6  f4 06 b7 ed
>|   ee 38 6b fb  5a 89 9f a5  ae 9f 24 11  7c 4b 1f e6
>|   49 28 66 51  ec e6 53 81  ff ff ff ff  ff ff ff ff
>| NSS: Value of base:
>|   02
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_PENDING_DDNS in 59 seconds
>| next event EVENT_PENDING_DDNS in 59 seconds
>| NSS: generated dh priv and pub keys: 128 
>| NSS: Local DH secret (pointer): 0x7f255c005b20 
>| NSS: Public DH value sent(computed in NSS):
>|   c9 80 f5 50  4a 4e f4 72  86 49 03 64  7e ff ae 74
>|   b5 00 de 04  72 3b 3f 73  8a fd d2 ec  42 d4 3b da
>|   01 1e b6 ef  94 b9 ab 58  93 93 54 32  d6 29 53 86
>|   d3 5c 47 49  19 7c 8f 1d  b0 a2 14 dd  e4 a1 67 a8
>|   8b 89 ad 40  7d fb 98 1e  22 d9 2b 0d  63 33 41 1b
>|   85 14 79 1f  b4 03 c9 44  d9 3a 36 41  cc 92 e9 72
>|   72 d4 79 ae  78 01 3d 5d  42 3d b4 b0  c3 40 3d 0f
>|   1c 36 5f ce  7f db f0 c0  09 d8 72 7f  dc 7a cc 40
>| NSS: Local DH public value (pointer): 0x7f255c005310 
>| reaped addconn helper child
>| Generated nonce:
>|   4b d1 d6 74  07 e1 f6 a7  2f 87 d5 1d  7a 84 d3 b2
>|  
>| crypto helper 0 has finished work (pcw_work now 1)
>| crypto helper 0 replies to request ID 1
>| calling continuation function 0x7f25695d42b0
>| ikev2_parent_outI1_continue for #1: calculated ke+nonce, sending I1
>| processing connection ikev2
>| #1 ikev2_parent_outI1_continue:284 st->st_calculating = FALSE;
>| ikev2_parent_outI1_tail for #1
>| saving DH priv (local secret) and pub key into state struct
>| **emit ISAKMP Message:
>|    initiator cookie:
>|   a5 6c 9f 5e  29 9d e7 03
>|    responder cookie:
>|   00 00 00 00  00 00 00 00
>|    next payload type: ISAKMP_NEXT_v2SA
>|    ISAKMP version: IKEv2 version 2.0 (rfc4306/rfc5996)
>|    exchange type: ISAKMP_v2_SA_INIT
>|    flags: ISAKMP_FLAG_IKE_INIT
>|    message ID:  00 00 00 00
>| ***emit IKEv2 Security Association Payload:
>|    next payload type: ISAKMP_NEXT_v2KE
>|    critical bit: none
>| ****emit IKEv2 Proposal Substructure Payload:
>|    last proposal: v2_PROPOSAL_LAST
>|    prop #: 1
>|    proto ID: IKEv2_SEC_PROTO_IKE
>|    spi size: 0
>|    # transforms: 4
>| *****emit IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_NON_LAST
>|    IKEv2 transform type: TRANS_TYPE_ENCR
>|    IKEv2 transform ID: 3DES
>| emitting length of IKEv2 Transform Substructure Payload: 8
>| *****emit IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_NON_LAST
>|    IKEv2 transform type: TRANS_TYPE_INTEG
>|    IKEv2 transform ID: AUTH_HMAC_SHA1_96
>| emitting length of IKEv2 Transform Substructure Payload: 8
>| *****emit IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_NON_LAST
>|    IKEv2 transform type: TRANS_TYPE_PRF
>|    IKEv2 transform ID: PRF_HMAC_SHA1
>| emitting length of IKEv2 Transform Substructure Payload: 8
>| *****emit IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_LAST
>|    IKEv2 transform type: TRANS_TYPE_DH
>|    IKEv2 transform ID: OAKLEY_GROUP_MODP1024
>| emitting length of IKEv2 Transform Substructure Payload: 8
>| emitting length of IKEv2 Proposal Substructure Payload: 40
>| emitting length of IKEv2 Security Association Payload: 44
>| ***emit IKEv2 Key Exchange Payload:
>|    IKEv2 next payload type: ISAKMP_NEXT_v2Ni
>|    critical bit: none
>|    DH group: OAKLEY_GROUP_MODP1024
>| emitting 128 raw bytes of ikev2 g^x into IKEv2 Key Exchange Payload
>| ikev2 g^x  c9 80 f5 50  4a 4e f4 72  86 49 03 64  7e ff ae 74
>| ikev2 g^x  b5 00 de 04  72 3b 3f 73  8a fd d2 ec  42 d4 3b da
>| ikev2 g^x  01 1e b6 ef  94 b9 ab 58  93 93 54 32  d6 29 53 86
>| ikev2 g^x  d3 5c 47 49  19 7c 8f 1d  b0 a2 14 dd  e4 a1 67 a8
>| ikev2 g^x  8b 89 ad 40  7d fb 98 1e  22 d9 2b 0d  63 33 41 1b
>| ikev2 g^x  85 14 79 1f  b4 03 c9 44  d9 3a 36 41  cc 92 e9 72
>| ikev2 g^x  72 d4 79 ae  78 01 3d 5d  42 3d b4 b0  c3 40 3d 0f
>| ikev2 g^x  1c 36 5f ce  7f db f0 c0  09 d8 72 7f  dc 7a cc 40
>| emitting length of IKEv2 Key Exchange Payload: 136
>| ***emit IKEv2 Nonce Payload:
>|    next payload type: ISAKMP_NEXT_v2N
>|    critical bit: none
>| emitting 16 raw bytes of IKEv2 nonce into IKEv2 Nonce Payload
>| IKEv2 nonce  4b d1 d6 74  07 e1 f6 a7  2f 87 d5 1d  7a 84 d3 b2
>| emitting length of IKEv2 Nonce Payload: 20
>|  NAT-Traversal support  [enabled] add v2N payloads.
>| natd_hash: Warning, rcookie is zero !!
>| natd_hash: hasher=0x7f25698935c0(20)
>| natd_hash: icookie=  a5 6c 9f 5e  29 9d e7 03
>| natd_hash: rcookie=  00 00 00 00  00 00 00 00
>| natd_hash: port=500
>| natd_hash: hash=  53 e5 0e 67  ea 06 0d a8  71 b6 98 a9  1f 03 01 dc
>| natd_hash: hash=  30 af ff 9d
>| Adding a v2N Payload
>| ***emit IKEv2 Notify Payload:
>|    next payload type: ISAKMP_NEXT_v2N
>|    critical bit: none
>|    Protocol ID: PROTO_RESERVED
>|    SPI size: 0
>|    Notify Message Type: v2N_NAT_DETECTION_SOURCE_IP
>| emitting 20 raw bytes of Notify data into IKEv2 Notify Payload
>| Notify data  53 e5 0e 67  ea 06 0d a8  71 b6 98 a9  1f 03 01 dc
>| Notify data  30 af ff 9d
>| emitting length of IKEv2 Notify Payload: 28
>| natd_hash: Warning, rcookie is zero !!
>| natd_hash: hasher=0x7f25698935c0(20)
>| natd_hash: icookie=  a5 6c 9f 5e  29 9d e7 03
>| natd_hash: rcookie=  00 00 00 00  00 00 00 00
>| natd_hash: port=500
>| natd_hash: hash=  8a d7 8b 69  1d 57 4f bd  f4 b6 48 df  1b a8 bf f0
>| natd_hash: hash=  c5 da 2b 65
>| Adding a v2N Payload
>| ***emit IKEv2 Notify Payload:
>|    next payload type: ISAKMP_NEXT_v2NONE
>|    critical bit: none
>|    Protocol ID: PROTO_RESERVED
>|    SPI size: 0
>|    Notify Message Type: v2N_NAT_DETECTION_DESTINATION_IP
>| emitting 20 raw bytes of Notify data into IKEv2 Notify Payload
>| Notify data  8a d7 8b 69  1d 57 4f bd  f4 b6 48 df  1b a8 bf f0
>| Notify data  c5 da 2b 65
>| emitting length of IKEv2 Notify Payload: 28
>| no IKE message padding required
>| emitting length of ISAKMP Message: 284
>| sending 284 bytes for ikev2_parent_outI1_common through p6p1:500 to 2001:db8:f:1::1:500 (using #1)
>|   a5 6c 9f 5e  29 9d e7 03  00 00 00 00  00 00 00 00
>|   21 20 22 08  00 00 00 00  00 00 01 1c  22 00 00 2c
>|   00 00 00 28  01 01 00 04  03 00 00 08  01 00 00 03
>|   03 00 00 08  03 00 00 02  03 00 00 08  02 00 00 02
>|   00 00 00 08  04 00 00 02  28 00 00 88  00 02 00 00
>|   c9 80 f5 50  4a 4e f4 72  86 49 03 64  7e ff ae 74
>|   b5 00 de 04  72 3b 3f 73  8a fd d2 ec  42 d4 3b da
>|   01 1e b6 ef  94 b9 ab 58  93 93 54 32  d6 29 53 86
>|   d3 5c 47 49  19 7c 8f 1d  b0 a2 14 dd  e4 a1 67 a8
>|   8b 89 ad 40  7d fb 98 1e  22 d9 2b 0d  63 33 41 1b
>|   85 14 79 1f  b4 03 c9 44  d9 3a 36 41  cc 92 e9 72
>|   72 d4 79 ae  78 01 3d 5d  42 3d b4 b0  c3 40 3d 0f
>|   1c 36 5f ce  7f db f0 c0  09 d8 72 7f  dc 7a cc 40
>|   29 00 00 14  4b d1 d6 74  07 e1 f6 a7  2f 87 d5 1d
>|   7a 84 d3 b2  29 00 00 1c  00 00 40 04  53 e5 0e 67
>|   ea 06 0d a8  71 b6 98 a9  1f 03 01 dc  30 af ff 9d
>|   00 00 00 1c  00 00 40 05  8a d7 8b 69  1d 57 4f bd
>|   f4 b6 48 df  1b a8 bf f0  c5 da 2b 65
>| deleting event for #1
>| inserting event EVENT_v2_RETRANSMIT, timeout in 10 seconds for #1
>| event added at head of queue
>| complete v2 state transition with STF_OK
>"ikev2" #1: transition from state STATE_IKEv2_START to state STATE_PARENT_I1
>"ikev2" #1: STATE_PARENT_I1: sent v2I1, expected v2R1
>| V2 microcode entry (initiate IKE_SA_INIT) has unspecified timeout_event
>| * processed 1 messages from cryptographic helpers 
>| next event EVENT_v2_RETRANSMIT in 10 seconds for #1
>| next event EVENT_v2_RETRANSMIT in 10 seconds for #1
>|  
>| next event EVENT_v2_RETRANSMIT in 0 seconds for #1
>| *time to handle event
>| handling event EVENT_v2_RETRANSMIT
>| event after this is EVENT_PENDING_DDNS in 49 seconds
>| processing connection ikev2
>| handling event EVENT_v2_RETRANSMIT for 2001:db8:f:1::1 "ikev2" #1 attempt 2 of 0
>| sending 284 bytes for EVENT_v2_RETRANSMIT through p6p1:500 to 2001:db8:f:1::1:500 (using #1)
>|   a5 6c 9f 5e  29 9d e7 03  00 00 00 00  00 00 00 00
>|   21 20 22 08  00 00 00 00  00 00 01 1c  22 00 00 2c
>|   00 00 00 28  01 01 00 04  03 00 00 08  01 00 00 03
>|   03 00 00 08  03 00 00 02  03 00 00 08  02 00 00 02
>|   00 00 00 08  04 00 00 02  28 00 00 88  00 02 00 00
>|   c9 80 f5 50  4a 4e f4 72  86 49 03 64  7e ff ae 74
>|   b5 00 de 04  72 3b 3f 73  8a fd d2 ec  42 d4 3b da
>|   01 1e b6 ef  94 b9 ab 58  93 93 54 32  d6 29 53 86
>|   d3 5c 47 49  19 7c 8f 1d  b0 a2 14 dd  e4 a1 67 a8
>|   8b 89 ad 40  7d fb 98 1e  22 d9 2b 0d  63 33 41 1b
>|   85 14 79 1f  b4 03 c9 44  d9 3a 36 41  cc 92 e9 72
>|   72 d4 79 ae  78 01 3d 5d  42 3d b4 b0  c3 40 3d 0f
>|   1c 36 5f ce  7f db f0 c0  09 d8 72 7f  dc 7a cc 40
>|   29 00 00 14  4b d1 d6 74  07 e1 f6 a7  2f 87 d5 1d
>|   7a 84 d3 b2  29 00 00 1c  00 00 40 04  53 e5 0e 67
>|   ea 06 0d a8  71 b6 98 a9  1f 03 01 dc  30 af ff 9d
>|   00 00 00 1c  00 00 40 05  8a d7 8b 69  1d 57 4f bd
>|   f4 b6 48 df  1b a8 bf f0  c5 da 2b 65
>| inserting event EVENT_v2_RETRANSMIT, timeout in 10 seconds for #1
>| event added at head of queue
>| next event EVENT_v2_RETRANSMIT in 10 seconds for #1
>|  
>| next event EVENT_v2_RETRANSMIT in 0 seconds for #1
>| *time to handle event
>| handling event EVENT_v2_RETRANSMIT
>| event after this is EVENT_PENDING_DDNS in 39 seconds
>| processing connection ikev2
>| handling event EVENT_v2_RETRANSMIT for 2001:db8:f:1::1 "ikev2" #1 attempt 2 of 0
>| sending 284 bytes for EVENT_v2_RETRANSMIT through p6p1:500 to 2001:db8:f:1::1:500 (using #1)
>|   a5 6c 9f 5e  29 9d e7 03  00 00 00 00  00 00 00 00
>|   21 20 22 08  00 00 00 00  00 00 01 1c  22 00 00 2c
>|   00 00 00 28  01 01 00 04  03 00 00 08  01 00 00 03
>|   03 00 00 08  03 00 00 02  03 00 00 08  02 00 00 02
>|   00 00 00 08  04 00 00 02  28 00 00 88  00 02 00 00
>|   c9 80 f5 50  4a 4e f4 72  86 49 03 64  7e ff ae 74
>|   b5 00 de 04  72 3b 3f 73  8a fd d2 ec  42 d4 3b da
>|   01 1e b6 ef  94 b9 ab 58  93 93 54 32  d6 29 53 86
>|   d3 5c 47 49  19 7c 8f 1d  b0 a2 14 dd  e4 a1 67 a8
>|   8b 89 ad 40  7d fb 98 1e  22 d9 2b 0d  63 33 41 1b
>|   85 14 79 1f  b4 03 c9 44  d9 3a 36 41  cc 92 e9 72
>|   72 d4 79 ae  78 01 3d 5d  42 3d b4 b0  c3 40 3d 0f
>|   1c 36 5f ce  7f db f0 c0  09 d8 72 7f  dc 7a cc 40
>|   29 00 00 14  4b d1 d6 74  07 e1 f6 a7  2f 87 d5 1d
>|   7a 84 d3 b2  29 00 00 1c  00 00 40 04  53 e5 0e 67
>|   ea 06 0d a8  71 b6 98 a9  1f 03 01 dc  30 af ff 9d
>|   00 00 00 1c  00 00 40 05  8a d7 8b 69  1d 57 4f bd
>|   f4 b6 48 df  1b a8 bf f0  c5 da 2b 65
>| inserting event EVENT_v2_RETRANSMIT, timeout in 20 seconds for #1
>| event added at head of queue
>| next event EVENT_v2_RETRANSMIT in 20 seconds for #1
>|  
>| *received 423 bytes from 2001:db8:f:1::1:500 on p6p1 (port=500)
>|   e4 d9 bd e8  36 f6 51 77  00 00 00 00  00 00 00 00
>|   21 20 22 08  00 00 00 00  00 00 01 a7  22 00 00 2c
>|   00 00 00 28  01 01 00 04  03 00 00 08  01 00 00 03
>|   03 00 00 08  02 00 00 02  03 00 00 08  03 00 00 02
>|   00 00 00 08  04 00 00 02  28 00 00 88  00 02 00 00
>|   ca 38 ca c1  e5 cd 35 3d  07 90 c9 c9  44 7f c1 58
>|   01 73 4e b1  4d 7a 02 7b  8e b7 c0 06  0a 84 39 51
>|   e9 88 ac 14  dc eb 29 f4  e4 b8 c0 ac  d8 f7 13 75
>|   30 89 84 42  94 60 fa cc  57 4f 24 e7  f9 bf 10 5b
>|   0a a1 59 4c  93 ae 79 c5  76 9c 6f 8e  a2 29 40 9d
>|   8c 31 d8 f6  f7 a7 8b aa  c3 fc 0e 35  9b 2e be 42
>|   61 aa 61 68  25 a0 a3 ad  43 62 9f 72  8b 86 3c 72
>|   cb d5 97 1b  a2 50 0c ea  c3 ec 3f fe  b6 65 f9 c9
>|   00 00 00 d7  e7 df 53 36  c2 41 b6 f5  a1 ba 61 36
>|   0a 30 e8 5e  31 3b 63 bf  80 90 f3 cf  3e 54 6a 6f
>|   c5 d7 17 77  8d 70 22 37  74 d0 bb a8  e0 02 a3 fd
>|   03 c4 c8 b0  8a da d9 53  67 4d 9d 81  e0 70 c6 78
>|   4a 68 dd 8a  71 dd 89 7a  6c 8f c6 15  d7 17 a2 88
>|   fb 97 f9 89  d0 bb a6 70  1d 97 7d 35  ec 51 bf 62
>|   e2 a8 7a fd  3e ed 10 d9  04 4a 9d ed  d4 54 e6 ba
>|   a0 34 e8 ea  82 d8 59 75  ca f4 5b a2  a0 f6 2a a8
>|   ff d7 0d f5  a9 95 b1 68  8c 9d de b8  37 ae 40 30
>|   4a ea 20 17  6f 13 49 c4  36 be 00 b6  f5 57 52 8c
>|   27 66 72 09  f2 e8 bf 99  6c 0a e8 b7  96 cc 4b ba
>|   fd 8c af f3  ef 42 a9 19  e7 32 f9 c5  ec 95 b7 19
>|   98 06 72 03  f3 41 ce 64  53 11 80 ff  22 01 4f e9
>|   01 ad 0e 61  58 a3 fe
>| **parse ISAKMP Message:
>|    initiator cookie:
>|   e4 d9 bd e8  36 f6 51 77
>|    responder cookie:
>|   00 00 00 00  00 00 00 00
>|    next payload type: ISAKMP_NEXT_v2SA
>|    ISAKMP version: IKEv2 version 2.0 (rfc4306/rfc5996)
>|    exchange type: ISAKMP_v2_SA_INIT
>|    flags: ISAKMP_FLAG_IKE_INIT
>|    message ID:  00 00 00 00
>|    length: 423
>|  processing version=2.0 packet with exchange type=ISAKMP_v2_SA_INIT (34)
>| I am receiving an IKE Request
>| I am the IKE SA Original Responder
>| ICOOKIE:  e4 d9 bd e8  36 f6 51 77
>| RCOOKIE:  00 00 00 00  00 00 00 00
>| state hash entry 22
>| parent v2 state object not found
>| ICOOKIE:  e4 d9 bd e8  36 f6 51 77
>| RCOOKIE:  00 00 00 00  00 00 00 00
>| state hash entry 22
>| parent_init v2 state object not found
>| selected state microcode Respond to IKE_SA_INIT
>| Now let's proceed with payload (ISAKMP_NEXT_v2SA)
>| ***parse IKEv2 Security Association Payload:
>|    next payload type: ISAKMP_NEXT_v2KE
>|    critical bit: none
>|    length: 44
>| processing payload: ISAKMP_NEXT_v2SA (len=44) 
>| Now let's proceed with payload (ISAKMP_NEXT_v2KE)
>| ***parse IKEv2 Key Exchange Payload:
>|    IKEv2 next payload type: ISAKMP_NEXT_v2Ni
>|    critical bit: none
>|    length: 136
>|    DH group: OAKLEY_GROUP_MODP1024
>| processing payload: ISAKMP_NEXT_v2KE (len=136) 
>| Now let's proceed with payload (ISAKMP_NEXT_v2Ni)
>| ***parse IKEv2 Nonce Payload:
>|    next payload type: ISAKMP_NEXT_v2NONE
>|    critical bit: none
>|    length: 215
>| processing payload: ISAKMP_NEXT_v2Ni (len=215) 
>| Now lets proceed with state specific processing
>| calling processor Respond to IKE_SA_INIT
>| will not send/process a dcookie
>| find_host_connection me=2001:db8:1:1::1234:500 him=2001:db8:f:1::1:500 policy=IKEV2_ALLOW
>| find_host_pair: comparing to 2001:db8:1:1::1234:500 2001:db8:f:1::1:500 
>| find_host_pair_conn (find_host_connection): 2001:db8:1:1::1234:500 2001:db8:f:1::1:500 -> hp:ikev2 
>| searching for connection with policy = IKEV2_ALLOW
>| found policy = PSK+ENCRYPT+PFS+UP+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW (ikev2)
>| find_host_connection returns ikev2
>| found connection: ikev2 
>| creating state object #2 at 0x7f256afbc080
>| processing connection ikev2
>| ICOOKIE:  e4 d9 bd e8  36 f6 51 77
>| RCOOKIE:  d4 86 3e 17  b8 49 d6 ca
>| state hash entry 22
>| inserting state object #2
>| inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #2
>| event added at head of queue
>| processing connection ikev2
>| crypto helper 0: pcw_work: 0
>| asking crypto helper 0 to do build_kenonce; request ID 2 (len=2768, pcw_work=0)
>| #2 send_crypto_helper_request:519 st->st_calculating = TRUE;
>| deleting event for #2
>| crypto helper 0 read fd: 8
>| crypto helper 0 doing build_kenonce; request ID 2
>| inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #2
>| event added after event EVENT_PENDING_PHASE2
>| complete v2 state transition with STF_SUSPEND
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_v2_RETRANSMIT in 19 seconds for #1
>| next event EVENT_v2_RETRANSMIT in 19 seconds for #1
>| NSS: Value of Prime:
>|   ff ff ff ff  ff ff ff ff  c9 0f da a2  21 68 c2 34
>|   c4 c6 62 8b  80 dc 1c d1  29 02 4e 08  8a 67 cc 74
>|   02 0b be a6  3b 13 9b 22  51 4a 08 79  8e 34 04 dd
>|   ef 95 19 b3  cd 3a 43 1b  30 2b 0a 6d  f2 5f 14 37
>|   4f e1 35 6d  6d 51 c2 45  e4 85 b5 76  62 5e 7e c6
>|   f4 4c 42 e9  a6 37 ed 6b  0b ff 5c b6  f4 06 b7 ed
>|   ee 38 6b fb  5a 89 9f a5  ae 9f 24 11  7c 4b 1f e6
>|   49 28 66 51  ec e6 53 81  ff ff ff ff  ff ff ff ff
>| NSS: Value of base:
>|   02
>| NSS: generated dh priv and pub keys: 128 
>| NSS: Local DH secret (pointer): 0x7f255c00aeb0 
>| NSS: Public DH value sent(computed in NSS):
>|   fe 9b 00 43  13 56 3c a6  44 75 4b 9a  0c 54 cc 0d
>|   34 62 f2 66  b5 a3 cc 79  4d 1b 81 7b  49 79 b4 bb
>|   23 3e 5e 16  fa b0 01 c4  38 62 e6 28  f8 ca 14 d0
>|   32 eb 80 0c  62 e0 d6 9c  98 45 0f 61  10 9f 6a 72
>|   a8 2a eb 6d  ab 07 83 3d  06 36 44 07  b5 f2 ea 5b
>|   2f eb b0 69  eb 15 ba 52  75 20 df 19  7a 89 e9 63
>|   1c 95 fa c6  66 0d 74 af  6c 59 0a b7  c7 b1 22 e7
>|   ea d9 8d f1  20 2d 3f 6a  33 92 57 09  1d 49 fb e9
>| NSS: Local DH public value (pointer): 0x7f255c00a6a0 
>| Generated nonce:
>|   4e 9d 57 74  25 de ad f7  5f 25 05 e2  83 6a fd 95
>|  
>| crypto helper 0 has finished work (pcw_work now 1)
>| crypto helper 0 replies to request ID 2
>| calling continuation function 0x7f25695d2050
>| ikev2_parent_inI1outR1_continue for #2: calculated ke+nonce, sending R1
>| processing connection ikev2
>| #2 ikev2_parent_inI1outR1_continue:847 st->st_calculating = FALSE;
>| **emit ISAKMP Message:
>|    initiator cookie:
>|   e4 d9 bd e8  36 f6 51 77
>|    responder cookie:
>|   d4 86 3e 17  b8 49 d6 ca
>|    next payload type: ISAKMP_NEXT_v2SA
>|    ISAKMP version: IKEv2 version 2.0 (rfc4306/rfc5996)
>|    exchange type: ISAKMP_v2_SA_INIT
>|    flags: ISAKMP_FLAG_MSG_RESPONSE
>|    message ID:  00 00 00 00
>| ***emit IKEv2 Security Association Payload:
>|    next payload type: ISAKMP_NEXT_v2KE
>|    critical bit: none
>| ****parse IKEv2 Proposal Substructure Payload:
>|    last proposal: v2_PROPOSAL_LAST
>|    length: 40
>|    prop #: 1
>|    proto ID: IKEv2_SEC_PROTO_IKE
>|    spi size: 0
>|    # transforms: 4
>| *****parse IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_NON_LAST
>|    length: 8
>|    IKEv2 transform type: TRANS_TYPE_ENCR
>|    IKEv2 transform ID: 3DES
>| *****parse IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_NON_LAST
>|    length: 8
>|    IKEv2 transform type: TRANS_TYPE_PRF
>|    IKEv2 transform ID: PRF_HMAC_SHA1
>| *****parse IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_NON_LAST
>|    length: 8
>|    IKEv2 transform type: TRANS_TYPE_INTEG
>|    IKEv2 transform ID: AUTH_HMAC_SHA1_96
>| *****parse IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_LAST
>|    length: 8
>|    IKEv2 transform type: TRANS_TYPE_DH
>|    IKEv2 transform ID: OAKLEY_GROUP_MODP1024
>| ipprotoid is '1'
>| considering Transform Type TRANS_TYPE_ENCR, TransID 3
>| encrid(3), keylen(-1), encr_keylen(-1)
>| proposal 1 succeeded encr= (policy:3DES(-1) vs offered:3DES(-1))
>| considering Transform Type TRANS_TYPE_INTEG, TransID 2
>|             succeeded integ=(policy:AUTH_HMAC_SHA1_96(-1) vs offered:AUTH_HMAC_SHA1_96(-1))
>| considering Transform Type TRANS_TYPE_PRF, TransID 2
>|             succeeded prf=  (policy:PRF_HMAC_SHA1(-1) vs offered:PRF_HMAC_SHA1(-1))
>| considering Transform Type TRANS_TYPE_DH, TransID 2
>|             succeeded dh=   (policy:OAKLEY_GROUP_MODP1024 vs offered:OAKLEY_GROUP_MODP1024)
>| ****emit IKEv2 Proposal Substructure Payload:
>|    last proposal: v2_PROPOSAL_LAST
>|    prop #: 1
>|    proto ID: IKEv2_SEC_PROTO_IKE
>|    spi size: 0
>|    # transforms: 4
>| *****emit IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_NON_LAST
>|    IKEv2 transform type: TRANS_TYPE_ENCR
>|    IKEv2 transform ID: 3DES
>| emitting length of IKEv2 Transform Substructure Payload: 8
>| *****emit IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_NON_LAST
>|    IKEv2 transform type: TRANS_TYPE_INTEG
>|    IKEv2 transform ID: AUTH_HMAC_SHA1_96
>| emitting length of IKEv2 Transform Substructure Payload: 8
>| *****emit IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_NON_LAST
>|    IKEv2 transform type: TRANS_TYPE_PRF
>|    IKEv2 transform ID: PRF_HMAC_SHA1
>| emitting length of IKEv2 Transform Substructure Payload: 8
>| *****emit IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_LAST
>|    IKEv2 transform type: TRANS_TYPE_DH
>|    IKEv2 transform ID: OAKLEY_GROUP_MODP1024
>| emitting length of IKEv2 Transform Substructure Payload: 8
>| emitting length of IKEv2 Proposal Substructure Payload: 40
>| emitting length of IKEv2 Security Association Payload: 44
>| DH public value received:
>|   ca 38 ca c1  e5 cd 35 3d  07 90 c9 c9  44 7f c1 58
>|   01 73 4e b1  4d 7a 02 7b  8e b7 c0 06  0a 84 39 51
>|   e9 88 ac 14  dc eb 29 f4  e4 b8 c0 ac  d8 f7 13 75
>|   30 89 84 42  94 60 fa cc  57 4f 24 e7  f9 bf 10 5b
>|   0a a1 59 4c  93 ae 79 c5  76 9c 6f 8e  a2 29 40 9d
>|   8c 31 d8 f6  f7 a7 8b aa  c3 fc 0e 35  9b 2e be 42
>|   61 aa 61 68  25 a0 a3 ad  43 62 9f 72  8b 86 3c 72
>|   cb d5 97 1b  a2 50 0c ea  c3 ec 3f fe  b6 65 f9 c9
>| saving DH priv (local secret) and pub key into state struct
>| ***emit IKEv2 Key Exchange Payload:
>|    IKEv2 next payload type: ISAKMP_NEXT_v2Ni
>|    critical bit: none
>|    DH group: OAKLEY_GROUP_MODP1024
>| emitting 128 raw bytes of ikev2 g^x into IKEv2 Key Exchange Payload
>| ikev2 g^x  fe 9b 00 43  13 56 3c a6  44 75 4b 9a  0c 54 cc 0d
>| ikev2 g^x  34 62 f2 66  b5 a3 cc 79  4d 1b 81 7b  49 79 b4 bb
>| ikev2 g^x  23 3e 5e 16  fa b0 01 c4  38 62 e6 28  f8 ca 14 d0
>| ikev2 g^x  32 eb 80 0c  62 e0 d6 9c  98 45 0f 61  10 9f 6a 72
>| ikev2 g^x  a8 2a eb 6d  ab 07 83 3d  06 36 44 07  b5 f2 ea 5b
>| ikev2 g^x  2f eb b0 69  eb 15 ba 52  75 20 df 19  7a 89 e9 63
>| ikev2 g^x  1c 95 fa c6  66 0d 74 af  6c 59 0a b7  c7 b1 22 e7
>| ikev2 g^x  ea d9 8d f1  20 2d 3f 6a  33 92 57 09  1d 49 fb e9
>| emitting length of IKEv2 Key Exchange Payload: 136
>| ***emit IKEv2 Nonce Payload:
>|    next payload type: ISAKMP_NEXT_v2N
>|    critical bit: none
>| emitting 16 raw bytes of IKEv2 nonce into IKEv2 Nonce Payload
>| IKEv2 nonce  4e 9d 57 74  25 de ad f7  5f 25 05 e2  83 6a fd 95
>| emitting length of IKEv2 Nonce Payload: 20
>|  NAT-Traversal support  [enabled] add v2N payloads.
>| natd_hash: hasher=0x7f25698935c0(20)
>| natd_hash: icookie=  e4 d9 bd e8  36 f6 51 77
>| natd_hash: rcookie=  d4 86 3e 17  b8 49 d6 ca
>| natd_hash: port=500
>| natd_hash: hash=  0a e6 76 5a  3a 20 37 26  59 0d 9e 52  71 f7 73 fc
>| natd_hash: hash=  ef 1a 1a a0
>| Adding a v2N Payload
>| ***emit IKEv2 Notify Payload:
>|    next payload type: ISAKMP_NEXT_v2N
>|    critical bit: none
>|    Protocol ID: PROTO_RESERVED
>|    SPI size: 0
>|    Notify Message Type: v2N_NAT_DETECTION_SOURCE_IP
>| emitting 20 raw bytes of Notify data into IKEv2 Notify Payload
>| Notify data  0a e6 76 5a  3a 20 37 26  59 0d 9e 52  71 f7 73 fc
>| Notify data  ef 1a 1a a0
>| emitting length of IKEv2 Notify Payload: 28
>| natd_hash: hasher=0x7f25698935c0(20)
>| natd_hash: icookie=  e4 d9 bd e8  36 f6 51 77
>| natd_hash: rcookie=  d4 86 3e 17  b8 49 d6 ca
>| natd_hash: port=500
>| natd_hash: hash=  37 ca 76 20  d9 bd 42 ff  8f 31 8e 16  e9 d0 20 65
>| natd_hash: hash=  e4 35 da eb
>| Adding a v2N Payload
>| ***emit IKEv2 Notify Payload:
>|    next payload type: ISAKMP_NEXT_v2NONE
>|    critical bit: none
>|    Protocol ID: PROTO_RESERVED
>|    SPI size: 0
>|    Notify Message Type: v2N_NAT_DETECTION_DESTINATION_IP
>| emitting 20 raw bytes of Notify data into IKEv2 Notify Payload
>| Notify data  37 ca 76 20  d9 bd 42 ff  8f 31 8e 16  e9 d0 20 65
>| Notify data  e4 35 da eb
>| emitting length of IKEv2 Notify Payload: 28
>| no IKE message padding required
>| emitting length of ISAKMP Message: 284
>| complete v2 state transition with STF_OK
>"ikev2" #2: transition from state STATE_IKEv2_START to state STATE_PARENT_R1
>"ikev2" #2: STATE_PARENT_R1: received v2I1, sent v2R1 {auth=IKEv2 cipher=oakley_3des_cbc_192 integ=sha1_96 prf=sha group=MODP1024}
>| sending reply packet to 2001:db8:f:1::1:500 (from port 500)
>| sending 284 bytes for STATE_IKEv2_START through p6p1:500 to 2001:db8:f:1::1:500 (using #2)
>|   e4 d9 bd e8  36 f6 51 77  d4 86 3e 17  b8 49 d6 ca
>|   21 20 22 20  00 00 00 00  00 00 01 1c  22 00 00 2c
>|   00 00 00 28  01 01 00 04  03 00 00 08  01 00 00 03
>|   03 00 00 08  03 00 00 02  03 00 00 08  02 00 00 02
>|   00 00 00 08  04 00 00 02  28 00 00 88  00 02 00 00
>|   fe 9b 00 43  13 56 3c a6  44 75 4b 9a  0c 54 cc 0d
>|   34 62 f2 66  b5 a3 cc 79  4d 1b 81 7b  49 79 b4 bb
>|   23 3e 5e 16  fa b0 01 c4  38 62 e6 28  f8 ca 14 d0
>|   32 eb 80 0c  62 e0 d6 9c  98 45 0f 61  10 9f 6a 72
>|   a8 2a eb 6d  ab 07 83 3d  06 36 44 07  b5 f2 ea 5b
>|   2f eb b0 69  eb 15 ba 52  75 20 df 19  7a 89 e9 63
>|   1c 95 fa c6  66 0d 74 af  6c 59 0a b7  c7 b1 22 e7
>|   ea d9 8d f1  20 2d 3f 6a  33 92 57 09  1d 49 fb e9
>|   29 00 00 14  4e 9d 57 74  25 de ad f7  5f 25 05 e2
>|   83 6a fd 95  29 00 00 1c  00 00 40 04  0a e6 76 5a
>|   3a 20 37 26  59 0d 9e 52  71 f7 73 fc  ef 1a 1a a0
>|   00 00 00 1c  00 00 40 05  37 ca 76 20  d9 bd 42 ff
>|   8f 31 8e 16  e9 d0 20 65  e4 35 da eb
>| deleting event for #2
>| inserting event EVENT_v2_RESPONDER_TIMEOUT, timeout in 200 seconds for #2
>| event added after event EVENT_PENDING_PHASE2
>| * processed 1 messages from cryptographic helpers 
>| next event EVENT_v2_RETRANSMIT in 19 seconds for #1
>| next event EVENT_v2_RETRANSMIT in 19 seconds for #1
>|  
>| *received 252 bytes from 2001:db8:f:1::1:500 on p6p1 (port=500)
>|   e4 d9 bd e8  36 f6 51 77  d4 86 3e 17  b8 49 d6 ca
>|   2e 20 23 08  00 00 00 01  00 00 00 fc  23 00 00 e0
>|   08 9c bf 56  ce bf 90 32  0e 6a 3c 5b  16 f2 d9 f5
>|   6e e7 da 84  82 b4 bd 2a  63 74 84 fe  2a f2 cc 17
>|   47 fa 4e 50  c4 8f 09 f5  64 c9 20 1b  57 03 3d 68
>|   89 d9 3d 8b  1e 52 04 88  6e 19 e8 e7  12 16 dc cd
>|   62 5b ef 77  0d 32 5b 36  05 d0 bc 1d  78 83 f3 ce
>|   8b 92 f7 d4  a9 86 ab c1  76 58 4d 0e  9d 1c e3 a6
>|   2c 95 32 a9  d8 bd 40 4a  d0 08 37 0e  a4 93 5e ea
>|   21 96 10 08  3f 65 93 50  a2 7e 5a 8d  8b 9b ee 1d
>|   f8 11 0d 64  af 4e 72 f0  90 79 db 09  a7 8a a9 ae
>|   79 d5 6d 72  35 40 7e 18  05 54 23 51  e5 fc 36 89
>|   ab 49 c5 bc  57 63 9e 6b  4d bb ce 13  b2 47 d5 f0
>|   f7 88 a7 33  46 e5 5b 51  43 c7 8a c8  8e c2 a3 91
>|   9d 73 c7 ba  d2 67 20 c7  5b be c0 3b  43 54 a0 c3
>|   06 b3 89 cf  5b 59 37 2f  8b e5 0c 67
>| **parse ISAKMP Message:
>|    initiator cookie:
>|   e4 d9 bd e8  36 f6 51 77
>|    responder cookie:
>|   d4 86 3e 17  b8 49 d6 ca
>|    next payload type: ISAKMP_NEXT_v2E
>|    ISAKMP version: IKEv2 version 2.0 (rfc4306/rfc5996)
>|    exchange type: ISAKMP_v2_AUTH
>|    flags: ISAKMP_FLAG_IKE_INIT
>|    message ID:  00 00 00 01
>|    length: 252
>|  processing version=2.0 packet with exchange type=ISAKMP_v2_AUTH (35)
>| I am receiving an IKE Request
>| I am the IKE SA Original Responder
>| ICOOKIE:  e4 d9 bd e8  36 f6 51 77
>| RCOOKIE:  d4 86 3e 17  b8 49 d6 ca
>| state hash entry 22
>| parent v2 peer and cookies match on #2
>| v2 state object #2 found, in STATE_PARENT_R1
>| state found and its state is STATE_PARENT_R1
>| selected state microcode respond to IKE_AUTH
>| #2 state_busy:1855 st != NULL && st->st_calculating == FALSE;
>| processing connection ikev2
>| Now let's proceed with payload (ISAKMP_NEXT_v2E)
>| ***parse IKEv2 Encryption Payload:
>|    next payload type: ISAKMP_NEXT_v2IDi
>|    critical bit: none
>|    length: 224
>| processing payload: ISAKMP_NEXT_v2E (len=224) 
>| Now lets proceed with state specific processing
>| calling processor respond to IKE_AUTH
>| ikev2 parent inI2outR2: calculating g^{xy} in order to decrypt I2
>| calculating skeyseed using prf=PRF_HMAC_SHA1 integ=AUTH_HMAC_SHA1_96 cipherkey=3DES
>| Copying DH pub key pointer to be sent to a thread helper
>| crypto helper 0: pcw_work: 0
>| asking crypto helper 0 to do compute dh (V2); request ID 3 (len=2768, pcw_work=0)
>| #2 send_crypto_helper_request:519 st->st_calculating = TRUE;
>| deleting event for #2
>| inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #2
>| event added after event EVENT_PENDING_PHASE2
>| complete v2 state transition with STF_SUSPEND
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_v2_RETRANSMIT in 18 seconds for #1
>| next event EVENT_v2_RETRANSMIT in 18 seconds for #1
>| crypto helper 0 read fd: 8
>| crypto helper 0 doing compute dh (V2); request ID 3
>| peer's g:   ca 38 ca c1  e5 cd 35 3d  07 90 c9 c9  44 7f c1 58
>| peer's g:   01 73 4e b1  4d 7a 02 7b  8e b7 c0 06  0a 84 39 51
>| peer's g:   e9 88 ac 14  dc eb 29 f4  e4 b8 c0 ac  d8 f7 13 75
>| peer's g:   30 89 84 42  94 60 fa cc  57 4f 24 e7  f9 bf 10 5b
>| peer's g:   0a a1 59 4c  93 ae 79 c5  76 9c 6f 8e  a2 29 40 9d
>| peer's g:   8c 31 d8 f6  f7 a7 8b aa  c3 fc 0e 35  9b 2e be 42
>| peer's g:   61 aa 61 68  25 a0 a3 ad  43 62 9f 72  8b 86 3c 72
>| peer's g:   cb d5 97 1b  a2 50 0c ea  c3 ec 3f fe  b6 65 f9 c9
>| Started DH shared-secret computation in NSS: 
>| Dropped no leading zeros 128
>| calc_dh_shared(): time elapsed (OAKLEY_GROUP_MODP1024): 734 usec
>| NSS: Started key computation 
>| calculating skeyseed using prf=PRF_HMAC_SHA1 integ=AUTH_HMAC_SHA1_96 cipherkey=24
>| skeyid inputs (digi+NI+NR+shared) hasher: oakley_sha
>| ni:   e7 df 53 36  c2 41 b6 f5  a1 ba 61 36  0a 30 e8 5e
>| ni:   31 3b 63 bf  80 90 f3 cf  3e 54 6a 6f  c5 d7 17 77
>| ni:   8d 70 22 37  74 d0 bb a8  e0 02 a3 fd  03 c4 c8 b0
>| ni:   8a da d9 53  67 4d 9d 81  e0 70 c6 78  4a 68 dd 8a
>| ni:   71 dd 89 7a  6c 8f c6 15  d7 17 a2 88  fb 97 f9 89
>| ni:   d0 bb a6 70  1d 97 7d 35  ec 51 bf 62  e2 a8 7a fd
>| ni:   3e ed 10 d9  04 4a 9d ed  d4 54 e6 ba  a0 34 e8 ea
>| ni:   82 d8 59 75  ca f4 5b a2  a0 f6 2a a8  ff d7 0d f5
>| ni:   a9 95 b1 68  8c 9d de b8  37 ae 40 30  4a ea 20 17
>| ni:   6f 13 49 c4  36 be 00 b6  f5 57 52 8c  27 66 72 09
>| ni:   f2 e8 bf 99  6c 0a e8 b7  96 cc 4b ba  fd 8c af f3
>| ni:   ef 42 a9 19  e7 32 f9 c5  ec 95 b7 19  98 06 72 03
>| ni:   f3 41 ce 64  53 11 80 ff  22 01 4f e9  01 ad 0e 61
>| ni:   58 a3 fe
>| nr:   4e 9d 57 74  25 de ad f7  5f 25 05 e2  83 6a fd 95
>| NSS: digisig skeyid pointer: 0x7f255c012400
>| PRF+ input
>| Ni  e7 df 53 36  c2 41 b6 f5  a1 ba 61 36  0a 30 e8 5e
>| Ni  31 3b 63 bf  80 90 f3 cf  3e 54 6a 6f  c5 d7 17 77
>| Ni  8d 70 22 37  74 d0 bb a8  e0 02 a3 fd  03 c4 c8 b0
>| Ni  8a da d9 53  67 4d 9d 81  e0 70 c6 78  4a 68 dd 8a
>| Ni  71 dd 89 7a  6c 8f c6 15  d7 17 a2 88  fb 97 f9 89
>| Ni  d0 bb a6 70  1d 97 7d 35  ec 51 bf 62  e2 a8 7a fd
>| Ni  3e ed 10 d9  04 4a 9d ed  d4 54 e6 ba  a0 34 e8 ea
>| Ni  82 d8 59 75  ca f4 5b a2  a0 f6 2a a8  ff d7 0d f5
>| Ni  a9 95 b1 68  8c 9d de b8  37 ae 40 30  4a ea 20 17
>| Ni  6f 13 49 c4  36 be 00 b6  f5 57 52 8c  27 66 72 09
>| Ni  f2 e8 bf 99  6c 0a e8 b7  96 cc 4b ba  fd 8c af f3
>| Ni  ef 42 a9 19  e7 32 f9 c5  ec 95 b7 19  98 06 72 03
>| Ni  f3 41 ce 64  53 11 80 ff  22 01 4f e9  01 ad 0e 61
>| Ni  58 a3 fe
>| Nr  4e 9d 57 74  25 de ad f7  5f 25 05 e2  83 6a fd 95
>| SPIi  e4 d9 bd e8  36 f6 51 77
>| SPIr  d4 86 3e 17  b8 49 d6 ca
>| Total keysize needed 148
>| NSS ikev2: finished computing key material for IKEv2 SA 
>| NSS ikev2: finished computing individual keys for IKEv2 SA 
>| calc_skeyseed_v2 pointers: shared 0x7f255c00bff0, skeyseed 0x7f255c012400, SK_d 0x7f255c013c80, SK_ai 0x7f255c010ac0, SK_ar 0x7f255c013d10, SK_ei 0x7f255c00f130, SK_er 0x7f255c000d40, SK_pi 0x7f255c015730, SK_pr 0x7f255c017100
>|  
>| crypto helper 0 has finished work (pcw_work now 1)
>| crypto helper 0 replies to request ID 3
>| calling continuation function 0x7f25695d18e0
>| ikev2_parent_inI2outR2_continue for #2: calculating g^{xy}, sending R2
>| processing connection ikev2
>| #2 ikev2_parent_inI2outR2_continue:1864 st->st_calculating = FALSE;
>| hmac_update data value: 
>|   e4 d9 bd e8  36 f6 51 77  d4 86 3e 17  b8 49 d6 ca
>|   2e 20 23 08  00 00 00 01  00 00 00 fc  23 00 00 e0
>|   08 9c bf 56  ce bf 90 32  0e 6a 3c 5b  16 f2 d9 f5
>|   6e e7 da 84  82 b4 bd 2a  63 74 84 fe  2a f2 cc 17
>|   47 fa 4e 50  c4 8f 09 f5  64 c9 20 1b  57 03 3d 68
>|   89 d9 3d 8b  1e 52 04 88  6e 19 e8 e7  12 16 dc cd
>|   62 5b ef 77  0d 32 5b 36  05 d0 bc 1d  78 83 f3 ce
>|   8b 92 f7 d4  a9 86 ab c1  76 58 4d 0e  9d 1c e3 a6
>|   2c 95 32 a9  d8 bd 40 4a  d0 08 37 0e  a4 93 5e ea
>|   21 96 10 08  3f 65 93 50  a2 7e 5a 8d  8b 9b ee 1d
>|   f8 11 0d 64  af 4e 72 f0  90 79 db 09  a7 8a a9 ae
>|   79 d5 6d 72  35 40 7e 18  05 54 23 51  e5 fc 36 89
>|   ab 49 c5 bc  57 63 9e 6b  4d bb ce 13  b2 47 d5 f0
>|   f7 88 a7 33  46 e5 5b 51  43 c7 8a c8  8e c2 a3 91
>|   9d 73 c7 ba  d2 67 20 c7  5b be c0 3b  43 54 a0 c3
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| data being hmac:  e4 d9 bd e8  36 f6 51 77  d4 86 3e 17  b8 49 d6 ca
>| data being hmac:  2e 20 23 08  00 00 00 01  00 00 00 fc  23 00 00 e0
>| data being hmac:  08 9c bf 56  ce bf 90 32  0e 6a 3c 5b  16 f2 d9 f5
>| data being hmac:  6e e7 da 84  82 b4 bd 2a  63 74 84 fe  2a f2 cc 17
>| data being hmac:  47 fa 4e 50  c4 8f 09 f5  64 c9 20 1b  57 03 3d 68
>| data being hmac:  89 d9 3d 8b  1e 52 04 88  6e 19 e8 e7  12 16 dc cd
>| data being hmac:  62 5b ef 77  0d 32 5b 36  05 d0 bc 1d  78 83 f3 ce
>| data being hmac:  8b 92 f7 d4  a9 86 ab c1  76 58 4d 0e  9d 1c e3 a6
>| data being hmac:  2c 95 32 a9  d8 bd 40 4a  d0 08 37 0e  a4 93 5e ea
>| data being hmac:  21 96 10 08  3f 65 93 50  a2 7e 5a 8d  8b 9b ee 1d
>| data being hmac:  f8 11 0d 64  af 4e 72 f0  90 79 db 09  a7 8a a9 ae
>| data being hmac:  79 d5 6d 72  35 40 7e 18  05 54 23 51  e5 fc 36 89
>| data being hmac:  ab 49 c5 bc  57 63 9e 6b  4d bb ce 13  b2 47 d5 f0
>| data being hmac:  f7 88 a7 33  46 e5 5b 51  43 c7 8a c8  8e c2 a3 91
>| data being hmac:  9d 73 c7 ba  d2 67 20 c7  5b be c0 3b  43 54 a0 c3
>| R2 calculated auth:  06 b3 89 cf  5b 59 37 2f  8b e5 0c 67
>| R2  provided  auth:  06 b3 89 cf  5b 59 37 2f  8b e5 0c 67
>| authenticator matched
>| data before decryption:
>|   0e 6a 3c 5b  16 f2 d9 f5  6e e7 da 84  82 b4 bd 2a
>|   63 74 84 fe  2a f2 cc 17  47 fa 4e 50  c4 8f 09 f5
>|   64 c9 20 1b  57 03 3d 68  89 d9 3d 8b  1e 52 04 88
>|   6e 19 e8 e7  12 16 dc cd  62 5b ef 77  0d 32 5b 36
>|   05 d0 bc 1d  78 83 f3 ce  8b 92 f7 d4  a9 86 ab c1
>|   76 58 4d 0e  9d 1c e3 a6  2c 95 32 a9  d8 bd 40 4a
>|   d0 08 37 0e  a4 93 5e ea  21 96 10 08  3f 65 93 50
>|   a2 7e 5a 8d  8b 9b ee 1d  f8 11 0d 64  af 4e 72 f0
>|   90 79 db 09  a7 8a a9 ae  79 d5 6d 72  35 40 7e 18
>|   05 54 23 51  e5 fc 36 89  ab 49 c5 bc  57 63 9e 6b
>|   4d bb ce 13  b2 47 d5 f0  f7 88 a7 33  46 e5 5b 51
>|   43 c7 8a c8  8e c2 a3 91  9d 73 c7 ba  d2 67 20 c7
>|   5b be c0 3b  43 54 a0 c3
>| NSS: do_3des init start
>| NSS: do_3des init end
>| decrypted payload:  27 00 00 18  05 00 00 00  20 01 0d b8  00 0f 00 01
>| decrypted payload:  00 00 00 00  00 00 00 01  29 00 00 1c  02 00 00 00
>| decrypted payload:  75 6c 98 1a  20 cd b3 d5  74 77 fb 3a  14 a7 5a ba
>| decrypted payload:  da 94 1c 7d  21 00 00 08  00 00 40 07  2c 00 00 28
>| decrypted payload:  00 00 00 24  01 03 04 03  91 09 92 2e  03 00 00 08
>| decrypted payload:  01 00 00 03  03 00 00 08  03 00 00 02  00 00 00 08
>| decrypted payload:  05 00 00 00  2d 00 00 30  01 00 00 00  08 00 00 28
>| decrypted payload:  00 00 ff ff  20 01 0d b8  00 0f 00 01  00 00 00 00
>| decrypted payload:  00 00 00 01  20 01 0d b8  00 0f 00 01  00 00 00 00
>| decrypted payload:  00 00 00 01  00 00 00 30  01 00 00 00  08 00 00 28
>| decrypted payload:  00 00 ff ff  20 01 0d b8  00 01 00 01  00 00 00 00
>| decrypted payload:  00 00 12 34  20 01 0d b8  00 01 00 01  00 00 00 00
>| decrypted payload:  00 00 12 34  be 30 b8 03
>| striping 4 bytes as pad
>| Now let's proceed with payload (ISAKMP_NEXT_v2IDi)
>| **parse IKEv2 Identification Payload:
>|    next payload type: ISAKMP_NEXT_v2AUTH
>|    critical bit: none
>|    length: 24
>|    id_type: ID_IPV6_ADDR
>| processing payload: ISAKMP_NEXT_v2IDi (len=24) 
>| Now let's proceed with payload (ISAKMP_NEXT_v2AUTH)
>| **parse IKEv2 Authentication Payload:
>|    next payload type: ISAKMP_NEXT_v2N
>|    critical bit: none
>|    length: 28
>|    auth method: IKEv2_AUTH_SHARED
>| processing payload: ISAKMP_NEXT_v2AUTH (len=28) 
>| Now let's proceed with payload (ISAKMP_NEXT_v2N)
>| **parse IKEv2 Notify Payload:
>|    next payload type: ISAKMP_NEXT_v2SA
>|    critical bit: none
>|    length: 8
>|    Protocol ID: PROTO_RESERVED
>|    SPI size: 0
>|    Notify Message Type: v2N_USE_TRANSPORT_MODE
>| processing payload: ISAKMP_NEXT_v2N (len=8) 
>| Now let's proceed with payload (ISAKMP_NEXT_v2SA)
>| **parse IKEv2 Security Association Payload:
>|    next payload type: ISAKMP_NEXT_v2TSi
>|    critical bit: none
>|    length: 40
>| processing payload: ISAKMP_NEXT_v2SA (len=40) 
>| Now let's proceed with payload (ISAKMP_NEXT_v2TSi)
>| **parse IKEv2 Traffic Selector Payload:
>|    next payload type: ISAKMP_NEXT_v2TSr
>|    critical bit: none
>|    length: 48
>|    number of TS: 1
>| processing payload: ISAKMP_NEXT_v2TSi (len=48) 
>| Now let's proceed with payload (ISAKMP_NEXT_v2TSr)
>| **parse IKEv2 Traffic Selector Payload:
>|    next payload type: ISAKMP_NEXT_v2NONE
>|    critical bit: none
>|    length: 48
>|    number of TS: 1
>| processing payload: ISAKMP_NEXT_v2TSr (len=48) 
>"ikev2" #2: IKEv2 mode peer ID is ID_IPV6_ADDR: '2001:db8:f:1::1'
>| idhash verify I2  05 00 00 00  20 01 0d b8  00 0f 00 01  00 00 00 00
>| idhash verify I2  00 00 00 01
>| hmac_update data value: 
>|   05 00 00 00  20 01 0d b8  00 0f 00 01  00 00 00 00
>|   00 00 00 01
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| started looking for secret for 2001:db8:1:1::1234->2001:db8:f:1::1 of kind PPK_PSK
>| actually looking for secret for 2001:db8:1:1::1234->2001:db8:f:1::1 of kind PPK_PSK
>| line 1: key type PPK_PSK(2001:db8:1:1::1234) to type PPK_PSK 
>| 1: compared key %any to 2001:db8:1:1::1234 / 2001:db8:f:1::1 -> 2
>| 2: compared key %any to 2001:db8:1:1::1234 / 2001:db8:f:1::1 -> 2
>| line 1: match=2 
>| best_match 0>2 best=0x7f256afb9f20 (line=1)
>| concluding with best_match=2 best=0x7f256afb9f20 (lineno=1)
>| hmac_update data value: 
>|   4b 65 79 20  50 61 64 20  66 6f 72 20  49 4b 45 76
>|   32
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| negotiated prf: oakley_sha hash length: 20
>| inner prf output  39 cf c8 93  0c 25 cb 0e  02 cc 09 14  9e 4e 66 ea
>| inner prf output  6b 6a a6 1e
>| hmac_update data value: 
>|   e4 d9 bd e8  36 f6 51 77  00 00 00 00  00 00 00 00
>|   21 20 22 08  00 00 00 00  00 00 01 a7  22 00 00 2c
>|   00 00 00 28  01 01 00 04  03 00 00 08  01 00 00 03
>|   03 00 00 08  02 00 00 02  03 00 00 08  03 00 00 02
>|   00 00 00 08  04 00 00 02  28 00 00 88  00 02 00 00
>|   ca 38 ca c1  e5 cd 35 3d  07 90 c9 c9  44 7f c1 58
>|   01 73 4e b1  4d 7a 02 7b  8e b7 c0 06  0a 84 39 51
>|   e9 88 ac 14  dc eb 29 f4  e4 b8 c0 ac  d8 f7 13 75
>|   30 89 84 42  94 60 fa cc  57 4f 24 e7  f9 bf 10 5b
>|   0a a1 59 4c  93 ae 79 c5  76 9c 6f 8e  a2 29 40 9d
>|   8c 31 d8 f6  f7 a7 8b aa  c3 fc 0e 35  9b 2e be 42
>|   61 aa 61 68  25 a0 a3 ad  43 62 9f 72  8b 86 3c 72
>|   cb d5 97 1b  a2 50 0c ea  c3 ec 3f fe  b6 65 f9 c9
>|   00 00 00 d7  e7 df 53 36  c2 41 b6 f5  a1 ba 61 36
>|   0a 30 e8 5e  31 3b 63 bf  80 90 f3 cf  3e 54 6a 6f
>|   c5 d7 17 77  8d 70 22 37  74 d0 bb a8  e0 02 a3 fd
>|   03 c4 c8 b0  8a da d9 53  67 4d 9d 81  e0 70 c6 78
>|   4a 68 dd 8a  71 dd 89 7a  6c 8f c6 15  d7 17 a2 88
>|   fb 97 f9 89  d0 bb a6 70  1d 97 7d 35  ec 51 bf 62
>|   e2 a8 7a fd  3e ed 10 d9  04 4a 9d ed  d4 54 e6 ba
>|   a0 34 e8 ea  82 d8 59 75  ca f4 5b a2  a0 f6 2a a8
>|   ff d7 0d f5  a9 95 b1 68  8c 9d de b8  37 ae 40 30
>|   4a ea 20 17  6f 13 49 c4  36 be 00 b6  f5 57 52 8c
>|   27 66 72 09  f2 e8 bf 99  6c 0a e8 b7  96 cc 4b ba
>|   fd 8c af f3  ef 42 a9 19  e7 32 f9 c5  ec 95 b7 19
>|   98 06 72 03  f3 41 ce 64  53 11 80 ff  22 01 4f e9
>|   01 ad 0e 61  58 a3 fe
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>|   4e 9d 57 74  25 de ad f7  5f 25 05 e2  83 6a fd 95
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>|   cb 9c fa 81  65 ea f9 2d  fc b7 c3 2d  59 ca 7a 36
>|   fd d7 95 57
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| inputs to hash1 (first packet)
>|   e4 d9 bd e8  36 f6 51 77  00 00 00 00  00 00 00 00
>|   21 20 22 08  00 00 00 00  00 00 01 a7  22 00 00 2c
>|   00 00 00 28  01 01 00 04  03 00 00 08  01 00 00 03
>|   03 00 00 08  02 00 00 02  03 00 00 08  03 00 00 02
>|   00 00 00 08  04 00 00 02  28 00 00 88  00 02 00 00
>|   ca 38 ca c1  e5 cd 35 3d  07 90 c9 c9  44 7f c1 58
>|   01 73 4e b1  4d 7a 02 7b  8e b7 c0 06  0a 84 39 51
>|   e9 88 ac 14  dc eb 29 f4  e4 b8 c0 ac  d8 f7 13 75
>|   30 89 84 42  94 60 fa cc  57 4f 24 e7  f9 bf 10 5b
>|   0a a1 59 4c  93 ae 79 c5  76 9c 6f 8e  a2 29 40 9d
>|   8c 31 d8 f6  f7 a7 8b aa  c3 fc 0e 35  9b 2e be 42
>|   61 aa 61 68  25 a0 a3 ad  43 62 9f 72  8b 86 3c 72
>|   cb d5 97 1b  a2 50 0c ea  c3 ec 3f fe  b6 65 f9 c9
>|   00 00 00 d7  e7 df 53 36  c2 41 b6 f5  a1 ba 61 36
>|   0a 30 e8 5e  31 3b 63 bf  80 90 f3 cf  3e 54 6a 6f
>|   c5 d7 17 77  8d 70 22 37  74 d0 bb a8  e0 02 a3 fd
>|   03 c4 c8 b0  8a da d9 53  67 4d 9d 81  e0 70 c6 78
>|   4a 68 dd 8a  71 dd 89 7a  6c 8f c6 15  d7 17 a2 88
>|   fb 97 f9 89  d0 bb a6 70  1d 97 7d 35  ec 51 bf 62
>|   e2 a8 7a fd  3e ed 10 d9  04 4a 9d ed  d4 54 e6 ba
>|   a0 34 e8 ea  82 d8 59 75  ca f4 5b a2  a0 f6 2a a8
>|   ff d7 0d f5  a9 95 b1 68  8c 9d de b8  37 ae 40 30
>|   4a ea 20 17  6f 13 49 c4  36 be 00 b6  f5 57 52 8c
>|   27 66 72 09  f2 e8 bf 99  6c 0a e8 b7  96 cc 4b ba
>|   fd 8c af f3  ef 42 a9 19  e7 32 f9 c5  ec 95 b7 19
>|   98 06 72 03  f3 41 ce 64  53 11 80 ff  22 01 4f e9
>|   01 ad 0e 61  58 a3 fe
>| inputs to hash2 (responder nonce)
>|   4e 9d 57 74  25 de ad f7  5f 25 05 e2  83 6a fd 95
>| idhash  cb 9c fa 81  65 ea f9 2d  fc b7 c3 2d  59 ca 7a 36
>| idhash  fd d7 95 57
>| Received PSK auth octets
>|   75 6c 98 1a  20 cd b3 d5  74 77 fb 3a  14 a7 5a ba
>|   da 94 1c 7d
>| Calculated PSK auth octets
>|   75 6c 98 1a  20 cd b3 d5  74 77 fb 3a  14 a7 5a ba
>|   da 94 1c 7d
>|  notify payload detected, should be processed....
>| deleting event for #2
>| inserting event EVENT_SA_REPLACE, timeout in 3330 seconds for #2
>| event added after event EVENT_PENDING_PHASE2
>| **emit ISAKMP Message:
>|    initiator cookie:
>|   e4 d9 bd e8  36 f6 51 77
>|    responder cookie:
>|   d4 86 3e 17  b8 49 d6 ca
>|    next payload type: ISAKMP_NEXT_v2E
>|    ISAKMP version: IKEv2 version 2.0 (rfc4306/rfc5996)
>|    exchange type: ISAKMP_v2_AUTH
>|    flags: ISAKMP_FLAG_MSG_RESPONSE
>|    message ID:  00 00 00 01
>| ***emit IKEv2 Encryption Payload:
>|    next payload type: ISAKMP_NEXT_v2IDr
>|    critical bit: none
>| emitting 8 zero bytes of iv into IKEv2 Encryption Payload
>| IKEv2 thinking whether to send my certificate:
>|  my policy has no RSASIG, the policy is : PSK+ENCRYPT+PFS+UP+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW
>|  sendcert: CERT_ALWAYSSEND and I did not get a certificate request 
>|  so do not send cert.
>| I did not send a certificate because digital signatures are not being used. (PSK)
>| *****emit IKEv2 Identification Payload:
>|    next payload type: ISAKMP_NEXT_v2AUTH
>|    critical bit: none
>|    id_type: ID_IPV6_ADDR
>| emitting 16 raw bytes of my identity into IKEv2 Identification Payload
>| my identity  20 01 0d b8  00 01 00 01  00 00 00 00  00 00 12 34
>| emitting length of IKEv2 Identification Payload: 24
>| idhash calc R2  05 00 00 00  20 01 0d b8  00 01 00 01  00 00 00 00
>| idhash calc R2  00 00 12 34
>| hmac_update data value: 
>|   05 00 00 00  20 01 0d b8  00 01 00 01  00 00 00 00
>|   00 00 12 34
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| assembled IDr payload -- CERT next
>| CHILD SA proposals received
>| going to assemble AUTH payload
>| *****emit IKEv2 Authentication Payload:
>|    next payload type: ISAKMP_NEXT_v2SA
>|    critical bit: none
>|    auth method: IKEv2_AUTH_SHARED
>| started looking for secret for 2001:db8:1:1::1234->2001:db8:f:1::1 of kind PPK_PSK
>| actually looking for secret for 2001:db8:1:1::1234->2001:db8:f:1::1 of kind PPK_PSK
>| line 1: key type PPK_PSK(2001:db8:1:1::1234) to type PPK_PSK 
>| 1: compared key %any to 2001:db8:1:1::1234 / 2001:db8:f:1::1 -> 2
>| 2: compared key %any to 2001:db8:1:1::1234 / 2001:db8:f:1::1 -> 2
>| line 1: match=2 
>| best_match 0>2 best=0x7f256afb9f20 (line=1)
>| concluding with best_match=2 best=0x7f256afb9f20 (lineno=1)
>| hmac_update data value: 
>|   4b 65 79 20  50 61 64 20  66 6f 72 20  49 4b 45 76
>|   32
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| negotiated prf: oakley_sha hash length: 20
>| inner prf output  39 cf c8 93  0c 25 cb 0e  02 cc 09 14  9e 4e 66 ea
>| inner prf output  6b 6a a6 1e
>| hmac_update data value: 
>|   e4 d9 bd e8  36 f6 51 77  d4 86 3e 17  b8 49 d6 ca
>|   21 20 22 20  00 00 00 00  00 00 01 1c  22 00 00 2c
>|   00 00 00 28  01 01 00 04  03 00 00 08  01 00 00 03
>|   03 00 00 08  03 00 00 02  03 00 00 08  02 00 00 02
>|   00 00 00 08  04 00 00 02  28 00 00 88  00 02 00 00
>|   fe 9b 00 43  13 56 3c a6  44 75 4b 9a  0c 54 cc 0d
>|   34 62 f2 66  b5 a3 cc 79  4d 1b 81 7b  49 79 b4 bb
>|   23 3e 5e 16  fa b0 01 c4  38 62 e6 28  f8 ca 14 d0
>|   32 eb 80 0c  62 e0 d6 9c  98 45 0f 61  10 9f 6a 72
>|   a8 2a eb 6d  ab 07 83 3d  06 36 44 07  b5 f2 ea 5b
>|   2f eb b0 69  eb 15 ba 52  75 20 df 19  7a 89 e9 63
>|   1c 95 fa c6  66 0d 74 af  6c 59 0a b7  c7 b1 22 e7
>|   ea d9 8d f1  20 2d 3f 6a  33 92 57 09  1d 49 fb e9
>|   29 00 00 14  4e 9d 57 74  25 de ad f7  5f 25 05 e2
>|   83 6a fd 95  29 00 00 1c  00 00 40 04  0a e6 76 5a
>|   3a 20 37 26  59 0d 9e 52  71 f7 73 fc  ef 1a 1a a0
>|   00 00 00 1c  00 00 40 05  37 ca 76 20  d9 bd 42 ff
>|   8f 31 8e 16  e9 d0 20 65  e4 35 da eb
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>|   e7 df 53 36  c2 41 b6 f5  a1 ba 61 36  0a 30 e8 5e
>|   31 3b 63 bf  80 90 f3 cf  3e 54 6a 6f  c5 d7 17 77
>|   8d 70 22 37  74 d0 bb a8  e0 02 a3 fd  03 c4 c8 b0
>|   8a da d9 53  67 4d 9d 81  e0 70 c6 78  4a 68 dd 8a
>|   71 dd 89 7a  6c 8f c6 15  d7 17 a2 88  fb 97 f9 89
>|   d0 bb a6 70  1d 97 7d 35  ec 51 bf 62  e2 a8 7a fd
>|   3e ed 10 d9  04 4a 9d ed  d4 54 e6 ba  a0 34 e8 ea
>|   82 d8 59 75  ca f4 5b a2  a0 f6 2a a8  ff d7 0d f5
>|   a9 95 b1 68  8c 9d de b8  37 ae 40 30  4a ea 20 17
>|   6f 13 49 c4  36 be 00 b6  f5 57 52 8c  27 66 72 09
>|   f2 e8 bf 99  6c 0a e8 b7  96 cc 4b ba  fd 8c af f3
>|   ef 42 a9 19  e7 32 f9 c5  ec 95 b7 19  98 06 72 03
>|   f3 41 ce 64  53 11 80 ff  22 01 4f e9  01 ad 0e 61
>|   58 a3 fe
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>|   f8 2b 53 00  0c bc 8c e6  8b ed f1 70  26 5e 54 f4
>|   85 21 93 1d
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| inputs to hash1 (first packet)
>|   e4 d9 bd e8  36 f6 51 77  d4 86 3e 17  b8 49 d6 ca
>|   21 20 22 20  00 00 00 00  00 00 01 1c  22 00 00 2c
>|   00 00 00 28  01 01 00 04  03 00 00 08  01 00 00 03
>|   03 00 00 08  03 00 00 02  03 00 00 08  02 00 00 02
>|   00 00 00 08  04 00 00 02  28 00 00 88  00 02 00 00
>|   fe 9b 00 43  13 56 3c a6  44 75 4b 9a  0c 54 cc 0d
>|   34 62 f2 66  b5 a3 cc 79  4d 1b 81 7b  49 79 b4 bb
>|   23 3e 5e 16  fa b0 01 c4  38 62 e6 28  f8 ca 14 d0
>|   32 eb 80 0c  62 e0 d6 9c  98 45 0f 61  10 9f 6a 72
>|   a8 2a eb 6d  ab 07 83 3d  06 36 44 07  b5 f2 ea 5b
>|   2f eb b0 69  eb 15 ba 52  75 20 df 19  7a 89 e9 63
>|   1c 95 fa c6  66 0d 74 af  6c 59 0a b7  c7 b1 22 e7
>|   ea d9 8d f1  20 2d 3f 6a  33 92 57 09  1d 49 fb e9
>|   29 00 00 14  4e 9d 57 74  25 de ad f7  5f 25 05 e2
>|   83 6a fd 95  29 00 00 1c  00 00 40 04  0a e6 76 5a
>|   3a 20 37 26  59 0d 9e 52  71 f7 73 fc  ef 1a 1a a0
>|   00 00 00 1c  00 00 40 05  37 ca 76 20  d9 bd 42 ff
>|   8f 31 8e 16  e9 d0 20 65  e4 35 da eb
>| inputs to hash2 (initiator nonce)
>|   e7 df 53 36  c2 41 b6 f5  a1 ba 61 36  0a 30 e8 5e
>|   31 3b 63 bf  80 90 f3 cf  3e 54 6a 6f  c5 d7 17 77
>|   8d 70 22 37  74 d0 bb a8  e0 02 a3 fd  03 c4 c8 b0
>|   8a da d9 53  67 4d 9d 81  e0 70 c6 78  4a 68 dd 8a
>|   71 dd 89 7a  6c 8f c6 15  d7 17 a2 88  fb 97 f9 89
>|   d0 bb a6 70  1d 97 7d 35  ec 51 bf 62  e2 a8 7a fd
>|   3e ed 10 d9  04 4a 9d ed  d4 54 e6 ba  a0 34 e8 ea
>|   82 d8 59 75  ca f4 5b a2  a0 f6 2a a8  ff d7 0d f5
>|   a9 95 b1 68  8c 9d de b8  37 ae 40 30  4a ea 20 17
>|   6f 13 49 c4  36 be 00 b6  f5 57 52 8c  27 66 72 09
>|   f2 e8 bf 99  6c 0a e8 b7  96 cc 4b ba  fd 8c af f3
>|   ef 42 a9 19  e7 32 f9 c5  ec 95 b7 19  98 06 72 03
>|   f3 41 ce 64  53 11 80 ff  22 01 4f e9  01 ad 0e 61
>|   58 a3 fe
>| idhash  f8 2b 53 00  0c bc 8c e6  8b ed f1 70  26 5e 54 f4
>| idhash  85 21 93 1d
>| PSK auth octets  e7 50 35 1a  cd 5a cf 47  e0 11 dd fd  d3 09 bf 51
>| PSK auth octets  71 83 39 7b
>| emitting 20 raw bytes of PSK auth into IKEv2 Authentication Payload
>| PSK auth  e7 50 35 1a  cd 5a cf 47  e0 11 dd fd  d3 09 bf 51
>| PSK auth  71 83 39 7b
>| emitting length of IKEv2 Authentication Payload: 28
>| ***parse IKEv2 Traffic Selector:
>|    TS type: IKEv2_TS_IPV6_ADDR_RANGE
>|    IP Protocol ID: 0
>|    length: 40
>|    start port: 0
>|    end port: 65535
>| parsing 16 raw bytes of IKEv2 Traffic Selector into ipv6 ts
>| ipv6 ts  20 01 0d b8  00 0f 00 01  00 00 00 00  00 00 00 01
>| parsing 16 raw bytes of IKEv2 Traffic Selector into ipv6 ts
>| ipv6 ts  20 01 0d b8  00 0f 00 01  00 00 00 00  00 00 00 01
>| ***parse IKEv2 Traffic Selector:
>|    TS type: IKEv2_TS_IPV6_ADDR_RANGE
>|    IP Protocol ID: 0
>|    length: 40
>|    start port: 0
>|    end port: 65535
>| parsing 16 raw bytes of IKEv2 Traffic Selector into ipv6 ts
>| ipv6 ts  20 01 0d b8  00 01 00 01  00 00 00 00  00 00 12 34
>| parsing 16 raw bytes of IKEv2 Traffic Selector into ipv6 ts
>| ipv6 ts  20 01 0d b8  00 01 00 01  00 00 00 00  00 00 12 34
>|   ikev2_evaluate_connection_fit evaluating our I=ikev2:2001:db8:f:1::1/128:0/0 R=2001:db8:1:1::1234/128:0/0  to their:
>|     tsi[0]=2001:db8:f:1::1/2001:db8:f:1::1 proto=0 portrange 0-65535, tsr[0]=2001:db8:1:1::1234/2001:db8:1:1::1234 proto=0 portrange 0-65535
>| ei->port 0  tsi[tsi_ni].startport 0  tsi[tsi_ni].endport 65535
>|       has ts_range1=0 maskbits1=128 ts_range2=0 maskbits2=128 fitbits=32896 <> -1
>| bfit_n=ikev2_evaluate_connection_fit found better fit c ikev2
>| ei->port 0  tsi[tsi_ni].startport 0  tsi[tsi_ni].endport 65535 narrowing=no
>|    tsi[0] 0-65535  ==  ei 0-65535 exact match all ports  fitrange1 65535
>|    tsr[0] 0-65535  ==  ei 0-65535 exact match all ports fitrange2 65535
>|     is a match
>|     and is a better fit tsi[0] fitrange1 65535 tsr[0] fitrange2 65535 fitbits 16842495
>|     port_fitness  16842495
>| ikev2_evaluate_connection_port_fit found better fit c ikev2, tsi[0],tsr[0]
>| ei->protocol 0  tsi[tsi_ni].ipprotoid 0 narrowing=no
>|    tsi[0] 0  ==  ei->protocol 0 exact match  fitrange1 255
>|    tsr[0] 0  ==  er->protocol 0 exact match  fitrange2 255
>|     is a match
>|     and is a better fit tsi[0] fitrange1 255 tsr[0] fitrange2 255 fitbits 65535
>|     protocol_fitnes  65535
>| ikev2_evaluate_connection_protocol_fit found better fit c ikev2, tsi[0],tsr[0]
>| find_host_pair: comparing to 2001:db8:1:1::1234:500 2001:db8:f:1::1:500 
>|   checking hostpair 2001:db8:1:1::1234/128 -> 2001:db8:f:1::1/128 is found
>|    match_id a=2001:db8:f:1::1
>|             b=2001:db8:f:1::1
>|    results  matched
>|   trusted_ca called with a=(empty) b=(empty)
>|   ikev2_evaluate_connection_fit evaluating our I=ikev2:2001:db8:f:1::1/128:0/0 R=2001:db8:1:1::1234/128:0/0  to their:
>|     tsi[0]=2001:db8:f:1::1/2001:db8:f:1::1 proto=0 portrange 0-65535, tsr[0]=2001:db8:1:1::1234/2001:db8:1:1::1234 proto=0 portrange 0-65535
>| ei->port 0  tsi[tsi_ni].startport 0  tsi[tsi_ni].endport 65535
>|       has ts_range1=0 maskbits1=128 ts_range2=0 maskbits2=128 fitbits=32896 <> -1
>| prefix range fit d ikev2 d->name was rejected by port matching
>| duplicating state object #2
>| creating state object #3 at 0x7f256afbcfb0
>| ICOOKIE:  e4 d9 bd e8  36 f6 51 77
>| RCOOKIE:  d4 86 3e 17  b8 49 d6 ca
>| state hash entry 22
>| inserting state object #3
>| inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #3
>| event added at head of queue
>| printing contents struct traffic_selector
>|   ts_type: IKEv2_TS_IPV6_ADDR_RANGE
>|   ipprotoid: 0
>|   startport: 0
>|   endport: 65535
>|   ip low: 2001:db8:1:1::1234
>|   ip high: 2001:db8:1:1::1234
>| printing contents struct traffic_selector
>|   ts_type: IKEv2_TS_IPV6_ADDR_RANGE
>|   ipprotoid: 0
>|   startport: 0
>|   endport: 65535
>|   ip low: 2001:db8:f:1::1
>|   ip high: 2001:db8:f:1::1
>| *****emit IKEv2 Security Association Payload:
>|    next payload type: ISAKMP_NEXT_v2TSi
>|    critical bit: none
>| entered ikev2_parse_child_sa_body()
>| kernel_alg_db_new() initial trans_cnt=128
>| kernel_alg_db_new() will return p_new->protoid=3, p_new->trans_cnt=1
>| kernel_alg_db_new()     trans[0]: transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=2
>| returning new proposal from esp_info
>| ***parse IKEv2 Proposal Substructure Payload:
>|    last proposal: v2_PROPOSAL_LAST
>|    length: 36
>|    prop #: 1
>|    proto ID: IKEv2_SEC_PROTO_ESP
>|    spi size: 4
>|    # transforms: 3
>| parsing 4 raw bytes of IKEv2 Proposal Substructure Payload into CHILD SA SPI
>| CHILD SA SPI  91 09 92 2e
>| ****parse IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_NON_LAST
>|    length: 8
>|    IKEv2 transform type: TRANS_TYPE_ENCR
>|    IKEv2 transform ID: 3DES
>| ****parse IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_NON_LAST
>|    length: 8
>|    IKEv2 transform type: TRANS_TYPE_INTEG
>|    IKEv2 transform ID: AUTH_HMAC_SHA1_96
>| ****parse IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_LAST
>|    length: 8
>|    IKEv2 transform type: TRANS_TYPE_ESN
>|    IKEv2 transform ID: ESN_DISABLED
>| Starting at transform type TRANS_TYPE_ENCR
>| failed proposal 1
>|             succeeded encr= (policy:3DES(-1) vs offered:3DES(-1))
>|             failed integ=(policy:AUTH_NONE(0) vs offered:AUTH_HMAC_SHA1_96(-1))
>|             failed esn=  (policy:ESN_DISABLED vs offered:ESN_DISABLED)
>| Starting at transform type TRANS_TYPE_INTEG
>| failed proposal 1
>|             succeeded encr= (policy:3DES(-1) vs offered:3DES(-1))
>|             succeeded integ=(policy:AUTH_HMAC_SHA1_96(-1) vs offered:AUTH_HMAC_SHA1_96(-1))
>|             failed esn=  (policy:ESN_DISABLED vs offered:ESN_DISABLED)
>| Starting at transform type TRANS_TYPE_ESN
>| matched proposal 1
>|             succeeded encr= (policy:3DES(-1) vs offered:3DES(-1))
>|             succeeded integ=(policy:AUTH_HMAC_SHA1_96(-1) vs offered:AUTH_HMAC_SHA1_96(-1))
>|             succeeded esn=  (policy:ESN_DISABLED vs offered:ESN_DISABLED)
>| kernel_alg_esp_enc_ok(3,192): OK
>| netlink_get_spi: allocated 0x705e15d5 for esp:0@2001:db8:1:1::1234
>| ******emit IKEv2 Proposal Substructure Payload:
>|    last proposal: v2_PROPOSAL_LAST
>|    prop #: 1
>|    proto ID: IKEv2_SEC_PROTO_ESP
>|    spi size: 4
>|    # transforms: 3
>| emitting 4 raw bytes of our spi into IKEv2 Proposal Substructure Payload
>| our spi  70 5e 15 d5
>| *******emit IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_NON_LAST
>|    IKEv2 transform type: TRANS_TYPE_ENCR
>|    IKEv2 transform ID: 3DES
>| emitting length of IKEv2 Transform Substructure Payload: 8
>| *******emit IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_NON_LAST
>|    IKEv2 transform type: TRANS_TYPE_INTEG
>|    IKEv2 transform ID: AUTH_HMAC_SHA1_96
>| emitting length of IKEv2 Transform Substructure Payload: 8
>| *******emit IKEv2 Transform Substructure Payload:
>|    last transform: v2_TRANSFORM_LAST
>|    IKEv2 transform type: TRANS_TYPE_ESN
>|    IKEv2 transform ID: ESN_DISABLED
>| emitting length of IKEv2 Transform Substructure Payload: 8
>| emitting length of IKEv2 Proposal Substructure Payload: 36
>| emitting length of IKEv2 Security Association Payload: 40
>| *****emit IKEv2 Traffic Selector Payload:
>|    next payload type: ISAKMP_NEXT_v2TSr
>|    critical bit: none
>|    number of TS: 1
>| ******emit IKEv2 Traffic Selector:
>|    TS type: IKEv2_TS_IPV6_ADDR_RANGE
>|    IP Protocol ID: 0
>|    start port: 0
>|    end port: 65535
>| emitting 16 raw bytes of ipv6 low into IKEv2 Traffic Selector
>| ipv6 low  20 01 0d b8  00 0f 00 01  00 00 00 00  00 00 00 01
>| emitting 16 raw bytes of ipv6 high into IKEv2 Traffic Selector
>| ipv6 high  20 01 0d b8  00 0f 00 01  00 00 00 00  00 00 00 01
>| emitting length of IKEv2 Traffic Selector: 40
>| emitting length of IKEv2 Traffic Selector Payload: 48
>| Received v2N_USE_TRANSPORT_MODE from the other end, next payload is v2N_USE_TRANSPORT_MODE notification
>| *****emit IKEv2 Traffic Selector Payload:
>|    next payload type: ISAKMP_NEXT_v2N
>|    critical bit: none
>|    number of TS: 1
>| ******emit IKEv2 Traffic Selector:
>|    TS type: IKEv2_TS_IPV6_ADDR_RANGE
>|    IP Protocol ID: 0
>|    start port: 0
>|    end port: 65535
>| emitting 16 raw bytes of ipv6 low into IKEv2 Traffic Selector
>| ipv6 low  20 01 0d b8  00 01 00 01  00 00 00 00  00 00 12 34
>| emitting 16 raw bytes of ipv6 high into IKEv2 Traffic Selector
>| ipv6 high  20 01 0d b8  00 01 00 01  00 00 00 00  00 00 12 34
>| emitting length of IKEv2 Traffic Selector: 40
>| emitting length of IKEv2 Traffic Selector Payload: 48
>| Local policy is transport, received USE_TRANSPORT_MODE
>| Now responding with USE_TRANSPORT_MODE notify
>| Adding a v2N Payload
>| *****emit IKEv2 Notify Payload:
>|    next payload type: ISAKMP_NEXT_v2NONE
>|    critical bit: none
>|    Protocol ID: PROTO_RESERVED
>|    SPI size: 0
>|    Notify Message Type: v2N_USE_TRANSPORT_MODE
>| emitting 0 raw bytes of Notify data into IKEv2 Notify Payload
>| Notify data
>| emitting length of IKEv2 Notify Payload: 8
>| kernel_alg_esp_info(): transid=3, auth=2, ei=0x7f2569899b80, enckeylen=24, authkeylen=20, encryptalg=3, authalg=3
>| hmac_update data value: 
>| 
>| hmac_update data value: 
>|   e7 df 53 36  c2 41 b6 f5  a1 ba 61 36  0a 30 e8 5e
>|   31 3b 63 bf  80 90 f3 cf  3e 54 6a 6f  c5 d7 17 77
>|   8d 70 22 37  74 d0 bb a8  e0 02 a3 fd  03 c4 c8 b0
>|   8a da d9 53  67 4d 9d 81  e0 70 c6 78  4a 68 dd 8a
>|   71 dd 89 7a  6c 8f c6 15  d7 17 a2 88  fb 97 f9 89
>|   d0 bb a6 70  1d 97 7d 35  ec 51 bf 62  e2 a8 7a fd
>|   3e ed 10 d9  04 4a 9d ed  d4 54 e6 ba  a0 34 e8 ea
>|   82 d8 59 75  ca f4 5b a2  a0 f6 2a a8  ff d7 0d f5
>|   a9 95 b1 68  8c 9d de b8  37 ae 40 30  4a ea 20 17
>|   6f 13 49 c4  36 be 00 b6  f5 57 52 8c  27 66 72 09
>|   f2 e8 bf 99  6c 0a e8 b7  96 cc 4b ba  fd 8c af f3
>|   ef 42 a9 19  e7 32 f9 c5  ec 95 b7 19  98 06 72 03
>|   f3 41 ce 64  53 11 80 ff  22 01 4f e9  01 ad 0e 61
>|   58 a3 fe
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>|   4e 9d 57 74  25 de ad f7  5f 25 05 e2  83 6a fd 95
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>| 
>| hmac_update data value: 
>| 
>| hmac_update data value: 
>|   01
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| prf+[1]:  51 65 de 6e  75 77 29 d5  cc 6f 36 ac  c5 79 98 d6
>| prf+[1]:  bc 1e 9f 61
>| hmac_update data value: 
>|   51 65 de 6e  75 77 29 d5  cc 6f 36 ac  c5 79 98 d6
>|   bc 1e 9f 61
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>|   e7 df 53 36  c2 41 b6 f5  a1 ba 61 36  0a 30 e8 5e
>|   31 3b 63 bf  80 90 f3 cf  3e 54 6a 6f  c5 d7 17 77
>|   8d 70 22 37  74 d0 bb a8  e0 02 a3 fd  03 c4 c8 b0
>|   8a da d9 53  67 4d 9d 81  e0 70 c6 78  4a 68 dd 8a
>|   71 dd 89 7a  6c 8f c6 15  d7 17 a2 88  fb 97 f9 89
>|   d0 bb a6 70  1d 97 7d 35  ec 51 bf 62  e2 a8 7a fd
>|   3e ed 10 d9  04 4a 9d ed  d4 54 e6 ba  a0 34 e8 ea
>|   82 d8 59 75  ca f4 5b a2  a0 f6 2a a8  ff d7 0d f5
>|   a9 95 b1 68  8c 9d de b8  37 ae 40 30  4a ea 20 17
>|   6f 13 49 c4  36 be 00 b6  f5 57 52 8c  27 66 72 09
>|   f2 e8 bf 99  6c 0a e8 b7  96 cc 4b ba  fd 8c af f3
>|   ef 42 a9 19  e7 32 f9 c5  ec 95 b7 19  98 06 72 03
>|   f3 41 ce 64  53 11 80 ff  22 01 4f e9  01 ad 0e 61
>|   58 a3 fe
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>|   4e 9d 57 74  25 de ad f7  5f 25 05 e2  83 6a fd 95
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>| 
>| hmac_update data value: 
>| 
>| hmac_update data value: 
>|   02
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| prf+[2]:  e7 9b e6 fe  10 d1 b6 bc  0b 19 ed 52  e6 df 6f a9
>| prf+[2]:  7d e2 ec e4
>| hmac_update data value: 
>|   e7 9b e6 fe  10 d1 b6 bc  0b 19 ed 52  e6 df 6f a9
>|   7d e2 ec e4
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>|   e7 df 53 36  c2 41 b6 f5  a1 ba 61 36  0a 30 e8 5e
>|   31 3b 63 bf  80 90 f3 cf  3e 54 6a 6f  c5 d7 17 77
>|   8d 70 22 37  74 d0 bb a8  e0 02 a3 fd  03 c4 c8 b0
>|   8a da d9 53  67 4d 9d 81  e0 70 c6 78  4a 68 dd 8a
>|   71 dd 89 7a  6c 8f c6 15  d7 17 a2 88  fb 97 f9 89
>|   d0 bb a6 70  1d 97 7d 35  ec 51 bf 62  e2 a8 7a fd
>|   3e ed 10 d9  04 4a 9d ed  d4 54 e6 ba  a0 34 e8 ea
>|   82 d8 59 75  ca f4 5b a2  a0 f6 2a a8  ff d7 0d f5
>|   a9 95 b1 68  8c 9d de b8  37 ae 40 30  4a ea 20 17
>|   6f 13 49 c4  36 be 00 b6  f5 57 52 8c  27 66 72 09
>|   f2 e8 bf 99  6c 0a e8 b7  96 cc 4b ba  fd 8c af f3
>|   ef 42 a9 19  e7 32 f9 c5  ec 95 b7 19  98 06 72 03
>|   f3 41 ce 64  53 11 80 ff  22 01 4f e9  01 ad 0e 61
>|   58 a3 fe
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>|   4e 9d 57 74  25 de ad f7  5f 25 05 e2  83 6a fd 95
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>| 
>| hmac_update data value: 
>| 
>| hmac_update data value: 
>|   03
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| prf+[3]:  26 aa 23 df  35 e7 bb 35  80 e6 61 f5  06 d1 2e ba
>| prf+[3]:  22 22 22 1b
>| hmac_update data value: 
>|   26 aa 23 df  35 e7 bb 35  80 e6 61 f5  06 d1 2e ba
>|   22 22 22 1b
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>|   e7 df 53 36  c2 41 b6 f5  a1 ba 61 36  0a 30 e8 5e
>|   31 3b 63 bf  80 90 f3 cf  3e 54 6a 6f  c5 d7 17 77
>|   8d 70 22 37  74 d0 bb a8  e0 02 a3 fd  03 c4 c8 b0
>|   8a da d9 53  67 4d 9d 81  e0 70 c6 78  4a 68 dd 8a
>|   71 dd 89 7a  6c 8f c6 15  d7 17 a2 88  fb 97 f9 89
>|   d0 bb a6 70  1d 97 7d 35  ec 51 bf 62  e2 a8 7a fd
>|   3e ed 10 d9  04 4a 9d ed  d4 54 e6 ba  a0 34 e8 ea
>|   82 d8 59 75  ca f4 5b a2  a0 f6 2a a8  ff d7 0d f5
>|   a9 95 b1 68  8c 9d de b8  37 ae 40 30  4a ea 20 17
>|   6f 13 49 c4  36 be 00 b6  f5 57 52 8c  27 66 72 09
>|   f2 e8 bf 99  6c 0a e8 b7  96 cc 4b ba  fd 8c af f3
>|   ef 42 a9 19  e7 32 f9 c5  ec 95 b7 19  98 06 72 03
>|   f3 41 ce 64  53 11 80 ff  22 01 4f e9  01 ad 0e 61
>|   58 a3 fe
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>|   4e 9d 57 74  25 de ad f7  5f 25 05 e2  83 6a fd 95
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>| 
>| hmac_update data value: 
>| 
>| hmac_update data value: 
>|   04
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| prf+[4]:  5b 21 3a c7  da b9 84 2d  9b 1f 6f 8a  3e 70 3b 10
>| prf+[4]:  a3 51 07 6e
>| hmac_update data value: 
>|   5b 21 3a c7  da b9 84 2d  9b 1f 6f 8a  3e 70 3b 10
>|   a3 51 07 6e
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>|   e7 df 53 36  c2 41 b6 f5  a1 ba 61 36  0a 30 e8 5e
>|   31 3b 63 bf  80 90 f3 cf  3e 54 6a 6f  c5 d7 17 77
>|   8d 70 22 37  74 d0 bb a8  e0 02 a3 fd  03 c4 c8 b0
>|   8a da d9 53  67 4d 9d 81  e0 70 c6 78  4a 68 dd 8a
>|   71 dd 89 7a  6c 8f c6 15  d7 17 a2 88  fb 97 f9 89
>|   d0 bb a6 70  1d 97 7d 35  ec 51 bf 62  e2 a8 7a fd
>|   3e ed 10 d9  04 4a 9d ed  d4 54 e6 ba  a0 34 e8 ea
>|   82 d8 59 75  ca f4 5b a2  a0 f6 2a a8  ff d7 0d f5
>|   a9 95 b1 68  8c 9d de b8  37 ae 40 30  4a ea 20 17
>|   6f 13 49 c4  36 be 00 b6  f5 57 52 8c  27 66 72 09
>|   f2 e8 bf 99  6c 0a e8 b7  96 cc 4b ba  fd 8c af f3
>|   ef 42 a9 19  e7 32 f9 c5  ec 95 b7 19  98 06 72 03
>|   f3 41 ce 64  53 11 80 ff  22 01 4f e9  01 ad 0e 61
>|   58 a3 fe
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>|   4e 9d 57 74  25 de ad f7  5f 25 05 e2  83 6a fd 95
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| hmac_update data value: 
>| 
>| hmac_update data value: 
>| 
>| hmac_update data value: 
>|   05
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| prf+[5]:  24 b4 a4 78  f4 6b ad a6  77 68 e6 10  f9 ff f9 d6
>| prf+[5]:  02 66 6f e4
>| our  keymat  51 65 de 6e  75 77 29 d5  cc 6f 36 ac  c5 79 98 d6
>| our  keymat  bc 1e 9f 61  e7 9b e6 fe  10 d1 b6 bc  0b 19 ed 52
>| our  keymat  e6 df 6f a9  7d e2 ec e4  26 aa 23 df
>| peer keymat  35 e7 bb 35  80 e6 61 f5  06 d1 2e ba  22 22 22 1b
>| peer keymat  5b 21 3a c7  da b9 84 2d  9b 1f 6f 8a  3e 70 3b 10
>| peer keymat  a3 51 07 6e  24 b4 a4 78  f4 6b ad a6
>| install_ipsec_sa() for #3: inbound and outbound
>| route owner of "ikev2" unrouted: NULL; eroute owner: NULL
>| could_route called for ikev2 (kind=CK_PERMANENT)
>| looking for alg with transid: 3 keylen: 192 auth: 2 
>| checking transid: 11 keylen: 0 auth: 1 
>| checking transid: 11 keylen: 0 auth: 2 
>| checking transid: 3 keylen: 24 auth: 0 
>| checking transid: 3 keylen: 24 auth: 1 
>| checking transid: 3 keylen: 24 auth: 2 
>| ESP enckey:  35 e7 bb 35  80 e6 61 f5  06 d1 2e ba  22 22 22 1b
>| ESP enckey:  5b 21 3a c7  da b9 84 2d
>| ESP authkey:  9b 1f 6f 8a  3e 70 3b 10  a3 51 07 6e  24 b4 a4 78
>| ESP authkey:  f4 6b ad a6
>| set up outgoing SA, ref=0/4294901761
>| looking for alg with transid: 3 keylen: 192 auth: 2 
>| checking transid: 11 keylen: 0 auth: 1 
>| checking transid: 11 keylen: 0 auth: 2 
>| checking transid: 3 keylen: 24 auth: 0 
>| checking transid: 3 keylen: 24 auth: 1 
>| checking transid: 3 keylen: 24 auth: 2 
>| ESP enckey:  51 65 de 6e  75 77 29 d5  cc 6f 36 ac  c5 79 98 d6
>| ESP enckey:  bc 1e 9f 61  e7 9b e6 fe
>| ESP authkey:  10 d1 b6 bc  0b 19 ed 52  e6 df 6f a9  7d e2 ec e4
>| ESP authkey:  26 aa 23 df
>| add inbound eroute 2001:db8:f:1::1/128:0 --0-> 2001:db8:1:1::1234/128:0 => esp:10000@2001:db8:1:1::1234 (raw_eroute)
>| satype(3) is not used in netlink_raw_eroute.
>| netlink_raw_eroute: using host address instead of client subnet
>| raw_eroute result=1 
>| set up incoming SA, ref=0/4294901761
>| sr for #3: unrouted
>| route owner of "ikev2" unrouted: NULL; eroute owner: NULL
>| route_and_eroute with c: ikev2 (next: none) ero:null esr:{(nil)} ro:null rosr:{(nil)} and state: 3
>| eroute_connection add eroute 2001:db8:1:1::1234/128:0 --0-> 2001:db8:f:1::1/128:0 => esp:9109922e@2001:db8:f:1::1 (raw_eroute)
>| satype(3) is not used in netlink_raw_eroute.
>| netlink_raw_eroute: using host address instead of client subnet
>| raw_eroute result=1 
>| command executing up-host-v6
>| executing up-host-v6: PLUTO_VERB='up-host-v6' PLUTO_VERSION='2.0' PLUTO_CONNECTION='ikev2' PLUTO_INTERFACE='p6p1' PLUTO_NEXT_HOP='2001:db8:f:1::1' PLUTO_ME='2001:db8:1:1::1234' PLUTO_MY_ID='2001:db8:1:1::1234' PLUTO_MY_CLIENT='2001:db8:1:1::1234/128' PLUTO_MY_CLIENT_NET='2001:db8:1:1::1234' PLUTO_MY_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16384' PLUTO_SA_TYPE='ESP' PLUTO_PEER='2001:db8:f:1::1' PLUTO_PEER_ID='2001:db8:f:1::1' PLUTO_PEER_CLIENT='2001:db8:f:1::1/128' PLUTO_PEER_CLIENT_NET='2001:db8:f:1::1' PLUTO_PEER_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey' PLUTO_ADDTIME='0' PLUTO_CONN_POLICY='PSK+ENCRYPT+PFS+UP+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW' PLUTO_CONN_ADDRFAMILY='ipv6' XAUTH_FAILED=0 PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO='' PLUTO_PEER_BANNER='' PLUTO_NM_CONFIGURED='0' ipsec _u
>| popen cmd is 1008 chars long
>| cmd(   0):PLUTO_VERB='up-host-v6' PLUTO_VERSION='2.0' PLUTO_CONNECTION='ikev2' PLUTO_INTER:
>| cmd(  80):FACE='p6p1' PLUTO_NEXT_HOP='2001:db8:f:1::1' PLUTO_ME='2001:db8:1:1::1234' PLUTO:
>| cmd( 160):_MY_ID='2001:db8:1:1::1234' PLUTO_MY_CLIENT='2001:db8:1:1::1234/128' PLUTO_MY_CL:
>| cmd( 240):IENT_NET='2001:db8:1:1::1234' PLUTO_MY_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:fff:
>| cmd( 320):f:ffff:ffff' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16384' PLUT:
>| cmd( 400):O_SA_TYPE='ESP' PLUTO_PEER='2001:db8:f:1::1' PLUTO_PEER_ID='2001:db8:f:1::1' PLU:
>| cmd( 480):TO_PEER_CLIENT='2001:db8:f:1::1/128' PLUTO_PEER_CLIENT_NET='2001:db8:f:1::1' PLU:
>| cmd( 560):TO_PEER_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_PEER_PORT='0:
>| cmd( 640):' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey' PLUTO_ADDTIME='0:
>| cmd( 720):' PLUTO_CONN_POLICY='PSK+ENCRYPT+PFS+UP+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PROPOSE+:
>| cmd( 800):SAREF_TRACK+IKE_FRAG_ALLOW' PLUTO_CONN_ADDRFAMILY='ipv6' XAUTH_FAILED=0 PLUTO_IS:
>| cmd( 880):_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO='' PLUTO_PEER_BANN:
>| cmd( 960):ER='' PLUTO_NM_CONFIGURED='0' ipsec _updown 2>&1:
>| route_and_eroute: firewall_notified: true
>| command executing prepare-host-v6
>| executing prepare-host-v6: PLUTO_VERB='prepare-host-v6' PLUTO_VERSION='2.0' PLUTO_CONNECTION='ikev2' PLUTO_INTERFACE='p6p1' PLUTO_NEXT_HOP='2001:db8:f:1::1' PLUTO_ME='2001:db8:1:1::1234' PLUTO_MY_ID='2001:db8:1:1::1234' PLUTO_MY_CLIENT='2001:db8:1:1::1234/128' PLUTO_MY_CLIENT_NET='2001:db8:1:1::1234' PLUTO_MY_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16384' PLUTO_SA_TYPE='ESP' PLUTO_PEER='2001:db8:f:1::1' PLUTO_PEER_ID='2001:db8:f:1::1' PLUTO_PEER_CLIENT='2001:db8:f:1::1/128' PLUTO_PEER_CLIENT_NET='2001:db8:f:1::1' PLUTO_PEER_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey' PLUTO_ADDTIME='0' PLUTO_CONN_POLICY='PSK+ENCRYPT+PFS+UP+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW' PLUTO_CONN_ADDRFAMILY='ipv6' XAUTH_FAILED=0 PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO='' PLUTO_PEER_BANNER='' PLUTO_NM_CONFIGURED='0
>| popen cmd is 1013 chars long
>| cmd(   0):PLUTO_VERB='prepare-host-v6' PLUTO_VERSION='2.0' PLUTO_CONNECTION='ikev2' PLUTO_:
>| cmd(  80):INTERFACE='p6p1' PLUTO_NEXT_HOP='2001:db8:f:1::1' PLUTO_ME='2001:db8:1:1::1234' :
>| cmd( 160):PLUTO_MY_ID='2001:db8:1:1::1234' PLUTO_MY_CLIENT='2001:db8:1:1::1234/128' PLUTO_:
>| cmd( 240):MY_CLIENT_NET='2001:db8:1:1::1234' PLUTO_MY_CLIENT_MASK='ffff:ffff:ffff:ffff:fff:
>| cmd( 320):f:ffff:ffff:ffff' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16384':
>| cmd( 400): PLUTO_SA_TYPE='ESP' PLUTO_PEER='2001:db8:f:1::1' PLUTO_PEER_ID='2001:db8:f:1::1:
>| cmd( 480):' PLUTO_PEER_CLIENT='2001:db8:f:1::1/128' PLUTO_PEER_CLIENT_NET='2001:db8:f:1::1:
>| cmd( 560):' PLUTO_PEER_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_PEER_PO:
>| cmd( 640):RT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey' PLUTO_ADDTI:
>| cmd( 720):ME='0' PLUTO_CONN_POLICY='PSK+ENCRYPT+PFS+UP+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PRO:
>| cmd( 800):POSE+SAREF_TRACK+IKE_FRAG_ALLOW' PLUTO_CONN_ADDRFAMILY='ipv6' XAUTH_FAILED=0 PLU:
>| cmd( 880):TO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO='' PLUTO_PEER:
>| cmd( 960):_BANNER='' PLUTO_NM_CONFIGURED='0' ipsec _updown 2>&1:
>| command executing route-host-v6
>| executing route-host-v6: PLUTO_VERB='route-host-v6' PLUTO_VERSION='2.0' PLUTO_CONNECTION='ikev2' PLUTO_INTERFACE='p6p1' PLUTO_NEXT_HOP='2001:db8:f:1::1' PLUTO_ME='2001:db8:1:1::1234' PLUTO_MY_ID='2001:db8:1:1::1234' PLUTO_MY_CLIENT='2001:db8:1:1::1234/128' PLUTO_MY_CLIENT_NET='2001:db8:1:1::1234' PLUTO_MY_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16384' PLUTO_SA_TYPE='ESP' PLUTO_PEER='2001:db8:f:1::1' PLUTO_PEER_ID='2001:db8:f:1::1' PLUTO_PEER_CLIENT='2001:db8:f:1::1/128' PLUTO_PEER_CLIENT_NET='2001:db8:f:1::1' PLUTO_PEER_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey' PLUTO_ADDTIME='0' PLUTO_CONN_POLICY='PSK+ENCRYPT+PFS+UP+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW' PLUTO_CONN_ADDRFAMILY='ipv6' XAUTH_FAILED=0 PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO='' PLUTO_PEER_BANNER='' PLUTO_NM_CONFIGURED='0' ip
>| popen cmd is 1011 chars long
>| cmd(   0):PLUTO_VERB='route-host-v6' PLUTO_VERSION='2.0' PLUTO_CONNECTION='ikev2' PLUTO_IN:
>| cmd(  80):TERFACE='p6p1' PLUTO_NEXT_HOP='2001:db8:f:1::1' PLUTO_ME='2001:db8:1:1::1234' PL:
>| cmd( 160):UTO_MY_ID='2001:db8:1:1::1234' PLUTO_MY_CLIENT='2001:db8:1:1::1234/128' PLUTO_MY:
>| cmd( 240):_CLIENT_NET='2001:db8:1:1::1234' PLUTO_MY_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff::
>| cmd( 320):ffff:ffff:ffff' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16384' P:
>| cmd( 400):LUTO_SA_TYPE='ESP' PLUTO_PEER='2001:db8:f:1::1' PLUTO_PEER_ID='2001:db8:f:1::1' :
>| cmd( 480):PLUTO_PEER_CLIENT='2001:db8:f:1::1/128' PLUTO_PEER_CLIENT_NET='2001:db8:f:1::1' :
>| cmd( 560):PLUTO_PEER_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_PEER_PORT:
>| cmd( 640):='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey' PLUTO_ADDTIME:
>| cmd( 720):='0' PLUTO_CONN_POLICY='PSK+ENCRYPT+PFS+UP+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PROPO:
>| cmd( 800):SE+SAREF_TRACK+IKE_FRAG_ALLOW' PLUTO_CONN_ADDRFAMILY='ipv6' XAUTH_FAILED=0 PLUTO:
>| cmd( 880):_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO='' PLUTO_PEER_B:
>| cmd( 960):ANNER='' PLUTO_NM_CONFIGURED='0' ipsec _updown 2>&1:
>| route_and_eroute: instance "ikev2", setting eroute_owner {spd=0x7f256afb8c40,sr=0x7f256afb8c40} to #3 (was #0) (newest_ipsec_sa=#0)
>| emitting 4 raw bytes of padding and length into cleartext
>| padding and length  00 01 02 03
>| emitting 12 zero bytes of length of truncated HMAC into IKEv2 Encryption Payload
>| emitting length of IKEv2 Encryption Payload: 224
>| emitting length of ISAKMP Message: 252
>| data before encryption:
>|   27 00 00 18  05 00 00 00  20 01 0d b8  00 01 00 01
>|   00 00 00 00  00 00 12 34  21 00 00 1c  02 00 00 00
>|   e7 50 35 1a  cd 5a cf 47  e0 11 dd fd  d3 09 bf 51
>|   71 83 39 7b  2c 00 00 28  00 00 00 24  01 03 04 03
>|   70 5e 15 d5  03 00 00 08  01 00 00 03  03 00 00 08
>|   03 00 00 02  00 00 00 08  05 00 00 00  2d 00 00 30
>|   01 00 00 00  08 00 00 28  00 00 ff ff  20 01 0d b8
>|   00 0f 00 01  00 00 00 00  00 00 00 01  20 01 0d b8
>|   00 0f 00 01  00 00 00 00  00 00 00 01  29 00 00 30
>|   01 00 00 00  08 00 00 28  00 00 ff ff  20 01 0d b8
>|   00 01 00 01  00 00 00 00  00 00 12 34  20 01 0d b8
>|   00 01 00 01  00 00 00 00  00 00 12 34  00 00 00 08
>|   00 00 40 07  00 01 02 03
>| NSS: do_3des init start
>| NSS: do_3des init end
>| data after encryption:
>|   e2 28 49 5d  59 bf e5 cd  2f 80 13 ae  08 25 63 a3
>|   ea 5d 47 fb  f4 e2 47 ac  03 b4 01 54  10 ba 17 20
>|   ea 08 8f 00  3d 55 c4 f4  46 ec 87 9c  82 da 0b 7d
>|   10 29 67 5a  30 d4 13 f8  83 9a 9a cb  69 02 0d 85
>|   a6 cc 83 d7  69 3e 1a 11  d5 3c 85 6e  20 24 94 7e
>|   fe 70 ee 90  1f ef 86 e6  ed 46 eb bf  9c af ac 4a
>|   76 30 6c 52  0b 83 51 a1  2a b6 87 9a  34 9c 15 bc
>|   24 d3 70 4a  37 18 f8 5c  81 70 4f 0c  44 0c 04 f3
>|   b7 6f 1e 13  75 9e 2c e1  78 6d c1 00  af e7 1d c5
>|   77 77 84 a0  c9 91 1f b1  52 b9 63 71  37 0b b7 81
>|   12 a4 c0 1e  0c 9e d5 2f  14 94 51 d1  49 54 86 a4
>|   16 1b e7 b4  cc 4b b9 5a  fa 0a ad 98  dd fa 81 dc
>|   1a 97 bc cd  ed f1 bf 2a
>| Inside authloc
>| authkey pointer: 0x7f255c013d10
>| Inside authloc after init
>| hmac_update data value: 
>|   e4 d9 bd e8  36 f6 51 77  d4 86 3e 17  b8 49 d6 ca
>|   2e 20 23 20  00 00 00 01  00 00 00 fc  24 00 00 e0
>|   88 41 e9 a1  39 aa 11 18  e2 28 49 5d  59 bf e5 cd
>|   2f 80 13 ae  08 25 63 a3  ea 5d 47 fb  f4 e2 47 ac
>|   03 b4 01 54  10 ba 17 20  ea 08 8f 00  3d 55 c4 f4
>|   46 ec 87 9c  82 da 0b 7d  10 29 67 5a  30 d4 13 f8
>|   83 9a 9a cb  69 02 0d 85  a6 cc 83 d7  69 3e 1a 11
>|   d5 3c 85 6e  20 24 94 7e  fe 70 ee 90  1f ef 86 e6
>|   ed 46 eb bf  9c af ac 4a  76 30 6c 52  0b 83 51 a1
>|   2a b6 87 9a  34 9c 15 bc  24 d3 70 4a  37 18 f8 5c
>|   81 70 4f 0c  44 0c 04 f3  b7 6f 1e 13  75 9e 2c e1
>|   78 6d c1 00  af e7 1d c5  77 77 84 a0  c9 91 1f b1
>|   52 b9 63 71  37 0b b7 81  12 a4 c0 1e  0c 9e d5 2f
>|   14 94 51 d1  49 54 86 a4  16 1b e7 b4  cc 4b b9 5a
>|   fa 0a ad 98  dd fa 81 dc  1a 97 bc cd  ed f1 bf 2a
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| Inside authloc after update
>| Inside authloc after final
>| data being hmac:  e4 d9 bd e8  36 f6 51 77  d4 86 3e 17  b8 49 d6 ca
>| data being hmac:  2e 20 23 20  00 00 00 01  00 00 00 fc  24 00 00 e0
>| data being hmac:  88 41 e9 a1  39 aa 11 18  e2 28 49 5d  59 bf e5 cd
>| data being hmac:  2f 80 13 ae  08 25 63 a3  ea 5d 47 fb  f4 e2 47 ac
>| data being hmac:  03 b4 01 54  10 ba 17 20  ea 08 8f 00  3d 55 c4 f4
>| data being hmac:  46 ec 87 9c  82 da 0b 7d  10 29 67 5a  30 d4 13 f8
>| data being hmac:  83 9a 9a cb  69 02 0d 85  a6 cc 83 d7  69 3e 1a 11
>| data being hmac:  d5 3c 85 6e  20 24 94 7e  fe 70 ee 90  1f ef 86 e6
>| data being hmac:  ed 46 eb bf  9c af ac 4a  76 30 6c 52  0b 83 51 a1
>| data being hmac:  2a b6 87 9a  34 9c 15 bc  24 d3 70 4a  37 18 f8 5c
>| data being hmac:  81 70 4f 0c  44 0c 04 f3  b7 6f 1e 13  75 9e 2c e1
>| data being hmac:  78 6d c1 00  af e7 1d c5  77 77 84 a0  c9 91 1f b1
>| data being hmac:  52 b9 63 71  37 0b b7 81  12 a4 c0 1e  0c 9e d5 2f
>| data being hmac:  14 94 51 d1  49 54 86 a4  16 1b e7 b4  cc 4b b9 5a
>| data being hmac:  fa 0a ad 98  dd fa 81 dc  1a 97 bc cd  ed f1 bf 2a
>| out calculated auth:
>|   6e f2 54 20  c4 ae 05 4c  87 5f 53 4a
>| complete v2 state transition with STF_OK
>"ikev2" #3: transition from state STATE_PARENT_R1 to state STATE_PARENT_R2
>"ikev2" #3: negotiated tunnel [2001:db8:1:1::1234,2001:db8:1:1::1234:0-65535 0] -> [2001:db8:f:1::1,2001:db8:f:1::1:0-65535 0]
>"ikev2" #3: STATE_PARENT_R2: received v2I2, PARENT SA established transport mode {ESP=>0x9109922e <0x705e15d5 xfrm=3DES_192-HMAC_SHA1 NATOA=none NATD=none DPD=passive}
>| sending reply packet to 2001:db8:f:1::1:500 (from port 500)
>| sending 252 bytes for STATE_PARENT_R1 through p6p1:500 to 2001:db8:f:1::1:500 (using #3)
>|   e4 d9 bd e8  36 f6 51 77  d4 86 3e 17  b8 49 d6 ca
>|   2e 20 23 20  00 00 00 01  00 00 00 fc  24 00 00 e0
>|   88 41 e9 a1  39 aa 11 18  e2 28 49 5d  59 bf e5 cd
>|   2f 80 13 ae  08 25 63 a3  ea 5d 47 fb  f4 e2 47 ac
>|   03 b4 01 54  10 ba 17 20  ea 08 8f 00  3d 55 c4 f4
>|   46 ec 87 9c  82 da 0b 7d  10 29 67 5a  30 d4 13 f8
>|   83 9a 9a cb  69 02 0d 85  a6 cc 83 d7  69 3e 1a 11
>|   d5 3c 85 6e  20 24 94 7e  fe 70 ee 90  1f ef 86 e6
>|   ed 46 eb bf  9c af ac 4a  76 30 6c 52  0b 83 51 a1
>|   2a b6 87 9a  34 9c 15 bc  24 d3 70 4a  37 18 f8 5c
>|   81 70 4f 0c  44 0c 04 f3  b7 6f 1e 13  75 9e 2c e1
>|   78 6d c1 00  af e7 1d c5  77 77 84 a0  c9 91 1f b1
>|   52 b9 63 71  37 0b b7 81  12 a4 c0 1e  0c 9e d5 2f
>|   14 94 51 d1  49 54 86 a4  16 1b e7 b4  cc 4b b9 5a
>|   fa 0a ad 98  dd fa 81 dc  1a 97 bc cd  ed f1 bf 2a
>|   6e f2 54 20  c4 ae 05 4c  87 5f 53 4a
>| releasing whack for #3 (sock=-1)
>| releasing whack and unpending for parent #2
>| unpending state #2
>| deleting event for #3
>| inserting event EVENT_SA_REPLACE, timeout in 28530 seconds for #3
>| event added after event EVENT_REINIT_SECRET
>| * processed 1 messages from cryptographic helpers 
>| next event EVENT_v2_RETRANSMIT in 18 seconds for #1
>| next event EVENT_v2_RETRANSMIT in 18 seconds for #1
>|  
>| *received 60 bytes from 2001:db8:f:1::1:500 on p6p1 (port=500)
>|   e4 d9 bd e8  36 f6 51 77  d4 86 3e 17  b8 49 d6 ca
>|   2e 20 25 49  00 00 00 02  00 00 00 3c  00 01 00 20
>|   37 37 07 bb  ef c0 4a a3  83 5a 09 d9  88 e6 8d 5d
>|   83 12 33 81  22 8d 14 34  be 30 81 01
>packet from 2001:db8:f:1::1:500: bitset flags of ISAKMP Message has unknown member(s): ISAKMP_FLAG_ENCRYPTION+ISAKMP_FLAG_IKE_INIT+0x40
>packet from 2001:db8:f:1::1:500: Received packet with mangled IKE header - dropped
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_v2_RETRANSMIT in 18 seconds for #1
>| next event EVENT_v2_RETRANSMIT in 18 seconds for #1
>|  
>| next event EVENT_v2_RETRANSMIT in 0 seconds for #1
>| *time to handle event
>| handling event EVENT_v2_RETRANSMIT
>| event after this is EVENT_PENDING_DDNS in 19 seconds
>| processing connection ikev2
>| handling event EVENT_v2_RETRANSMIT for 2001:db8:f:1::1 "ikev2" #1 attempt 2 of 0
>| sending 284 bytes for EVENT_v2_RETRANSMIT through p6p1:500 to 2001:db8:f:1::1:500 (using #1)
>|   a5 6c 9f 5e  29 9d e7 03  00 00 00 00  00 00 00 00
>|   21 20 22 08  00 00 00 00  00 00 01 1c  22 00 00 2c
>|   00 00 00 28  01 01 00 04  03 00 00 08  01 00 00 03
>|   03 00 00 08  03 00 00 02  03 00 00 08  02 00 00 02
>|   00 00 00 08  04 00 00 02  28 00 00 88  00 02 00 00
>|   c9 80 f5 50  4a 4e f4 72  86 49 03 64  7e ff ae 74
>|   b5 00 de 04  72 3b 3f 73  8a fd d2 ec  42 d4 3b da
>|   01 1e b6 ef  94 b9 ab 58  93 93 54 32  d6 29 53 86
>|   d3 5c 47 49  19 7c 8f 1d  b0 a2 14 dd  e4 a1 67 a8
>|   8b 89 ad 40  7d fb 98 1e  22 d9 2b 0d  63 33 41 1b
>|   85 14 79 1f  b4 03 c9 44  d9 3a 36 41  cc 92 e9 72
>|   72 d4 79 ae  78 01 3d 5d  42 3d b4 b0  c3 40 3d 0f
>|   1c 36 5f ce  7f db f0 c0  09 d8 72 7f  dc 7a cc 40
>|   29 00 00 14  4b d1 d6 74  07 e1 f6 a7  2f 87 d5 1d
>|   7a 84 d3 b2  29 00 00 1c  00 00 40 04  53 e5 0e 67
>|   ea 06 0d a8  71 b6 98 a9  1f 03 01 dc  30 af ff 9d
>|   00 00 00 1c  00 00 40 05  8a d7 8b 69  1d 57 4f bd
>|   f4 b6 48 df  1b a8 bf f0  c5 da 2b 65
>| inserting event EVENT_v2_RETRANSMIT, timeout in 40 seconds for #1
>| event added after event EVENT_PENDING_DDNS
>| next event EVENT_PENDING_DDNS in 19 seconds
>|  
>| *received whack message
>shutting down
>| certs and keys locked by 'free_preshared_secrets'
>forgetting secrets
>| certs and keys unlocked by 'free_preshard_secrets'
>| processing connection ikev2
>"ikev2": deleting connection
>| removing pending policy for "none" {0x7f256afba820}
>| processing connection ikev2
>"ikev2" #1: deleting state (STATE_PARENT_I1)
>| deleting event for #1
>| deleting state #1
>| deleting event for #1
>| ICOOKIE:  a5 6c 9f 5e  29 9d e7 03
>| RCOOKIE:  00 00 00 00  00 00 00 00
>| state hash entry 6
>| processing connection ikev2
>"ikev2" #3: deleting state (STATE_PARENT_R2)
>| deleting event for #3
>| deleting state #3
>"ikev2" #3: ESP traffic information: in=0B out=0B
>| **emit ISAKMP Message:
>|    initiator cookie:
>|   e4 d9 bd e8  36 f6 51 77
>|    responder cookie:
>|   d4 86 3e 17  b8 49 d6 ca
>|    next payload type: ISAKMP_NEXT_v2E
>|    ISAKMP version: IKEv2 version 2.0 (rfc4306/rfc5996)
>|    exchange type: ISAKMP_v2_INFORMATIONAL
>|    flags: none
>|    message ID:  00 00 00 00
>| ***emit IKEv2 Encryption Payload:
>|    next payload type: ISAKMP_NEXT_v2D
>|    critical bit: none
>| emitting 8 zero bytes of iv into IKEv2 Encryption Payload
>| *****emit IKEv2 Delete Payload:
>|    next payload type: ISAKMP_NEXT_v2NONE
>|    critical bit: none
>|    protocol ID: PROTO_IPSEC_ESP
>|    SPI size: 4
>|    number of SPIs: 1
>| emitting 4 raw bytes of local spis into IKEv2 Delete Payload
>| local spis  70 5e 15 d5
>| emitting length of IKEv2 Delete Payload: 12
>| emitting 4 raw bytes of padding and length into cleartext
>| padding and length  00 01 02 03
>| emitting 12 zero bytes of length of truncated HMAC into IKEv2 Encryption Payload
>| emitting length of IKEv2 Encryption Payload: 40
>| emitting length of ISAKMP Message: 68
>| data before encryption:
>|   00 00 00 0c  03 04 00 01  70 5e 15 d5  00 01 02 03
>| NSS: do_3des init start
>| NSS: do_3des init end
>| data after encryption:
>|   4e 00 9a 77  cf 44 da 22  66 0c bc df  d8 8c 3c d1
>| Inside authloc
>| authkey pointer: 0x7f255c013d10
>| Inside authloc after init
>| hmac_update data value: 
>|   e4 d9 bd e8  36 f6 51 77  d4 86 3e 17  b8 49 d6 ca
>|   2e 20 25 00  00 00 00 00  00 00 00 44  2a 00 00 28
>|   b2 42 fc 9c  1e 16 64 7f  4e 00 9a 77  cf 44 da 22
>|   66 0c bc df  d8 8c 3c d1
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| Inside authloc after update
>| Inside authloc after final
>| data being hmac:  e4 d9 bd e8  36 f6 51 77  d4 86 3e 17  b8 49 d6 ca
>| data being hmac:  2e 20 25 00  00 00 00 00  00 00 00 44  2a 00 00 28
>| data being hmac:  b2 42 fc 9c  1e 16 64 7f  4e 00 9a 77  cf 44 da 22
>| data being hmac:  66 0c bc df  d8 8c 3c d1
>| out calculated auth:
>|   8d 56 9a 38  69 b2 51 3c  73 c3 13 5b
>| sending 68 bytes for ikev2_delete_out through p6p1:500 to 2001:db8:f:1::1:500 (using #2)
>|   e4 d9 bd e8  36 f6 51 77  d4 86 3e 17  b8 49 d6 ca
>|   2e 20 25 00  00 00 00 00  00 00 00 44  2a 00 00 28
>|   b2 42 fc 9c  1e 16 64 7f  4e 00 9a 77  cf 44 da 22
>|   66 0c bc df  d8 8c 3c d1  8d 56 9a 38  69 b2 51 3c
>|   73 c3 13 5b
>| deleting event for #3
>| ICOOKIE:  e4 d9 bd e8  36 f6 51 77
>| RCOOKIE:  d4 86 3e 17  b8 49 d6 ca
>| state hash entry 22
>| command executing down-host-v6
>| executing down-host-v6: PLUTO_VERB='down-host-v6' PLUTO_VERSION='2.0' PLUTO_CONNECTION='ikev2' PLUTO_INTERFACE='p6p1' PLUTO_NEXT_HOP='2001:db8:f:1::1' PLUTO_ME='2001:db8:1:1::1234' PLUTO_MY_ID='2001:db8:1:1::1234' PLUTO_MY_CLIENT='2001:db8:1:1::1234/128' PLUTO_MY_CLIENT_NET='2001:db8:1:1::1234' PLUTO_MY_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16384' PLUTO_SA_TYPE='ESP' PLUTO_PEER='2001:db8:f:1::1' PLUTO_PEER_ID='2001:db8:f:1::1' PLUTO_PEER_CLIENT='2001:db8:f:1::1/128' PLUTO_PEER_CLIENT_NET='2001:db8:f:1::1' PLUTO_PEER_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey' PLUTO_ADDTIME='0' PLUTO_CONN_POLICY='PSK+ENCRYPT+PFS+UP+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW' PLUTO_CONN_ADDRFAMILY='ipv6' XAUTH_FAILED=0 PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO='' PLUTO_PEER_BANNER='' PLUTO_NM_CONFIGURED='0' ipse
>| popen cmd is 1010 chars long
>| cmd(   0):PLUTO_VERB='down-host-v6' PLUTO_VERSION='2.0' PLUTO_CONNECTION='ikev2' PLUTO_INT:
>| cmd(  80):ERFACE='p6p1' PLUTO_NEXT_HOP='2001:db8:f:1::1' PLUTO_ME='2001:db8:1:1::1234' PLU:
>| cmd( 160):TO_MY_ID='2001:db8:1:1::1234' PLUTO_MY_CLIENT='2001:db8:1:1::1234/128' PLUTO_MY_:
>| cmd( 240):CLIENT_NET='2001:db8:1:1::1234' PLUTO_MY_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:f:
>| cmd( 320):fff:ffff:ffff' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16384' PL:
>| cmd( 400):UTO_SA_TYPE='ESP' PLUTO_PEER='2001:db8:f:1::1' PLUTO_PEER_ID='2001:db8:f:1::1' P:
>| cmd( 480):LUTO_PEER_CLIENT='2001:db8:f:1::1/128' PLUTO_PEER_CLIENT_NET='2001:db8:f:1::1' P:
>| cmd( 560):LUTO_PEER_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_PEER_PORT=:
>| cmd( 640):'0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey' PLUTO_ADDTIME=:
>| cmd( 720):'0' PLUTO_CONN_POLICY='PSK+ENCRYPT+PFS+UP+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PROPOS:
>| cmd( 800):E+SAREF_TRACK+IKE_FRAG_ALLOW' PLUTO_CONN_ADDRFAMILY='ipv6' XAUTH_FAILED=0 PLUTO_:
>| cmd( 880):IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO='' PLUTO_PEER_BA:
>| cmd( 960):NNER='' PLUTO_NM_CONFIGURED='0' ipsec _updown 2>&1:
>| netlink_raw_eroute: using host address instead of client subnet
>| delete esp:9109922e@2001:db8:f:1::1
>| delete inbound eroute 2001:db8:f:1::1/128:0 --0-> 2001:db8:1:1::1234/128:0 => esp:10000@2001:db8:1:1::1234 (raw_eroute)
>| satype(3) is not used in netlink_raw_eroute.
>| netlink_raw_eroute: using host address instead of client subnet
>| raw_eroute result=1 
>| delete esp:705e15d5@2001:db8:1:1::1234
>| processing connection ikev2
>"ikev2" #2: deleting state (STATE_PARENT_R2)
>| deleting event for #2
>| deleting state #2
>| **emit ISAKMP Message:
>|    initiator cookie:
>|   e4 d9 bd e8  36 f6 51 77
>|    responder cookie:
>|   d4 86 3e 17  b8 49 d6 ca
>|    next payload type: ISAKMP_NEXT_v2E
>|    ISAKMP version: IKEv2 version 2.0 (rfc4306/rfc5996)
>|    exchange type: ISAKMP_v2_INFORMATIONAL
>|    flags: none
>|    message ID:  00 00 00 01
>| ***emit IKEv2 Encryption Payload:
>|    next payload type: ISAKMP_NEXT_v2D
>|    critical bit: none
>| emitting 8 zero bytes of iv into IKEv2 Encryption Payload
>| *****emit IKEv2 Delete Payload:
>|    next payload type: ISAKMP_NEXT_v2NONE
>|    critical bit: none
>|    protocol ID: PROTO_ISAKMP
>|    SPI size: 0
>|    number of SPIs: 0
>| emitting length of IKEv2 Delete Payload: 8
>| emitting 8 raw bytes of padding and length into cleartext
>| padding and length  00 01 02 03  04 05 06 07
>| emitting 12 zero bytes of length of truncated HMAC into IKEv2 Encryption Payload
>| emitting length of IKEv2 Encryption Payload: 40
>| emitting length of ISAKMP Message: 68
>| data before encryption:
>|   00 00 00 08  01 00 00 00  00 01 02 03  04 05 06 07
>| NSS: do_3des init start
>| NSS: do_3des init end
>| data after encryption:
>|   d8 26 67 f9  2d 97 a3 e7  fb 61 be 26  1c 31 52 14
>| Inside authloc
>| authkey pointer: 0x7f255c013d10
>| Inside authloc after init
>| hmac_update data value: 
>|   e4 d9 bd e8  36 f6 51 77  d4 86 3e 17  b8 49 d6 ca
>|   2e 20 25 00  00 00 00 01  00 00 00 44  2a 00 00 28
>|   39 cf 4e 77  30 e3 d4 69  d8 26 67 f9  2d 97 a3 e7
>|   fb 61 be 26  1c 31 52 14
>| hmac_update: inside if
>| hmac_update: after digest
>| hmac_update: after assert
>| Inside authloc after update
>| Inside authloc after final
>| data being hmac:  e4 d9 bd e8  36 f6 51 77  d4 86 3e 17  b8 49 d6 ca
>| data being hmac:  2e 20 25 00  00 00 00 01  00 00 00 44  2a 00 00 28
>| data being hmac:  39 cf 4e 77  30 e3 d4 69  d8 26 67 f9  2d 97 a3 e7
>| data being hmac:  fb 61 be 26  1c 31 52 14
>| out calculated auth:
>|   c2 0a 6c 6c  97 d5 48 38  94 98 e1 bd
>| sending 68 bytes for ikev2_delete_out through p6p1:500 to 2001:db8:f:1::1:500 (using #2)
>|   e4 d9 bd e8  36 f6 51 77  d4 86 3e 17  b8 49 d6 ca
>|   2e 20 25 00  00 00 00 01  00 00 00 44  2a 00 00 28
>|   39 cf 4e 77  30 e3 d4 69  d8 26 67 f9  2d 97 a3 e7
>|   fb 61 be 26  1c 31 52 14  c2 0a 6c 6c  97 d5 48 38
>|   94 98 e1 bd
>| deleting event for #2
>| ICOOKIE:  e4 d9 bd e8  36 f6 51 77
>| RCOOKIE:  d4 86 3e 17  b8 49 d6 ca
>| state hash entry 22
>| delete inbound eroute 2001:db8:f:1::1/128:0 --0-> 2001:db8:1:1::1234/128:0 => esp:10000@2001:db8:1:1::1234 (raw_eroute)
>| satype(3) is not used in netlink_raw_eroute.
>| netlink_raw_eroute: using host address instead of client subnet
>| raw_eroute result=1 
>| netlink_raw_eroute: using host address instead of client subnet
>| netlink_raw_eroute: using host address instead of client subnet
>| route owner of "ikev2" unrouted: NULL
>| command executing unroute-host-v6
>| executing unroute-host-v6: PLUTO_VERB='unroute-host-v6' PLUTO_VERSION='2.0' PLUTO_CONNECTION='ikev2' PLUTO_INTERFACE='p6p1' PLUTO_NEXT_HOP='2001:db8:f:1::1' PLUTO_ME='2001:db8:1:1::1234' PLUTO_MY_ID='2001:db8:1:1::1234' PLUTO_MY_CLIENT='2001:db8:1:1::1234/128' PLUTO_MY_CLIENT_NET='2001:db8:1:1::1234' PLUTO_MY_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16384' PLUTO_SA_TYPE='none' PLUTO_PEER='2001:db8:f:1::1' PLUTO_PEER_ID='2001:db8:f:1::1' PLUTO_PEER_CLIENT='2001:db8:f:1::1/128' PLUTO_PEER_CLIENT_NET='2001:db8:f:1::1' PLUTO_PEER_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey' PLUTO_ADDTIME='0' PLUTO_CONN_POLICY='PSK+ENCRYPT+PFS+UP+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PROPOSE+SAREF_TRACK+IKE_FRAG_ALLOW' PLUTO_CONN_ADDRFAMILY='ipv6' XAUTH_FAILED=0 PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO='' PLUTO_PEER_BANNER='' PLUTO_NM_CONFIGURED='
>| popen cmd is 1014 chars long
>| cmd(   0):PLUTO_VERB='unroute-host-v6' PLUTO_VERSION='2.0' PLUTO_CONNECTION='ikev2' PLUTO_:
>| cmd(  80):INTERFACE='p6p1' PLUTO_NEXT_HOP='2001:db8:f:1::1' PLUTO_ME='2001:db8:1:1::1234' :
>| cmd( 160):PLUTO_MY_ID='2001:db8:1:1::1234' PLUTO_MY_CLIENT='2001:db8:1:1::1234/128' PLUTO_:
>| cmd( 240):MY_CLIENT_NET='2001:db8:1:1::1234' PLUTO_MY_CLIENT_MASK='ffff:ffff:ffff:ffff:fff:
>| cmd( 320):f:ffff:ffff:ffff' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16384':
>| cmd( 400): PLUTO_SA_TYPE='none' PLUTO_PEER='2001:db8:f:1::1' PLUTO_PEER_ID='2001:db8:f:1:::
>| cmd( 480):1' PLUTO_PEER_CLIENT='2001:db8:f:1::1/128' PLUTO_PEER_CLIENT_NET='2001:db8:f:1:::
>| cmd( 560):1' PLUTO_PEER_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_PEER_P:
>| cmd( 640):ORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey' PLUTO_ADDT:
>| cmd( 720):IME='0' PLUTO_CONN_POLICY='PSK+ENCRYPT+PFS+UP+IKEV1_DISABLE+IKEV2_ALLOW+IKEV2_PR:
>| cmd( 800):OPOSE+SAREF_TRACK+IKE_FRAG_ALLOW' PLUTO_CONN_ADDRFAMILY='ipv6' XAUTH_FAILED=0 PL:
>| cmd( 880):UTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO='' PLUTO_PEE:
>| cmd( 960):R_BANNER='' PLUTO_NM_CONFIGURED='0' ipsec _updown 2>&1:
>| crl fetch request list locked by 'free_crl_fetch'
>| crl fetch request list unlocked by 'free_crl_fetch'
>| authcert list locked by 'free_authcerts'
>| authcert list unlocked by 'free_authcerts'
>| crl list locked by 'free_crls'
>| crl list unlocked by 'free_crls'
>shutting down interface lo/lo ::1:500
>shutting down interface p6p1/p6p1 2001:db8:1:1::1234:500
>shutting down interface lo/lo 127.0.0.1:4500
>shutting down interface lo/lo 127.0.0.1:500
>shutting down interface p7p1/p7p1 10.66.13.22:4500
>shutting down interface p7p1/p7p1 10.66.13.22:500

Actions: View

Attachments on bug 1157379: 950892