Attachment 861647 Details for Bug 759073 – other end log file

other end log file

rhel5b.log (text/x-log), 130.80 KB, created by Paul Wouters on 2014-02-11 02:21:36 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Paul Wouters

Created: 2014-02-11 02:21:36 UTC

Size: 130.80 KB

patch

obsolete

>Plutorun started on Mon Feb 10 21:16:52 EST 2014
>adjusting ipsec.d to /etc/ipsec.d
>nss directory plutomain: /etc/ipsec.d
>NSS Initialized
>Non-fips mode set in /proc/sys/crypto/fips_enabled
>Starting Pluto (Openswan Version 2.6.32; Vendor ID OEhyLdACecfa) pid:2792
>Non-fips mode set in /proc/sys/crypto/fips_enabled
>LEAK_DETECTIVE support [disabled]
>OCF support for IKE [disabled]
>SAref support [disabled]: Protocol not available
>SAbind support [disabled]: Protocol not available
>NSS support [enabled]
>HAVE_STATSD notification support not compiled in
>Setting NAT-Traversal port-4500 floating to off
>   port floating activation criteria nat_t=0/port_float=1
>   NAT-Traversal support  [disabled]
>| 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_enc(): Activating OAKLEY_BLOWFISH_CBC: Ok (ret=0)
>ike_alg_register_hash(): Activating OAKLEY_SHA2_512: Ok (ret=0)
>ike_alg_register_hash(): Activating OAKLEY_SHA2_256: Ok (ret=0)
>starting up 1 cryptographic helpers
>started helper (thread) pid=47595519617344 (fd:9)
>| status value returned by setting the priority of this thread (id=0) 22
>| helper 0 waiting on fd: 10
>Using Linux 2.6 IPsec interface code on 2.6.18-371.el5 (experimental code)
>| process 2792 listening for PF_KEY_V2 on file descriptor 13
>| finish_pfkey_msg: K_SADB_REGISTER message 1 for AH 
>|   02 07 00 02  02 00 00 00  01 00 00 00  e8 0a 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  e8 0a 00 00
>| pfkey_get: K_SADB_REGISTER message 2
>| alg_init():memset(0x2b49ac9bc880, 0, 2048) memset(0x2b49ac9bd080, 0, 2048) 
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: sadb_msg_len=19 sadb_supported_len=56
>| kernel_alg_add():satype=3, exttype=14, alg_id=251
>| 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
>| 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
>| 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
>| 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=8
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[4], exttype=14, satype=3, alg_id=8, alg_ivlen=0, alg_minbits=160, alg_maxbits=160, res=0, ret=1
>| kernel_alg_add():satype=3, exttype=14, alg_id=9
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[5], exttype=14, satype=3, alg_id=9, alg_ivlen=0, alg_minbits=128, alg_maxbits=128, res=0, ret=1
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: sadb_msg_len=19 sadb_supported_len=80
>| kernel_alg_add():satype=3, exttype=15, alg_id=11
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[6], exttype=15, satype=3, alg_id=11, alg_ivlen=0, alg_minbits=0, alg_maxbits=0, res=0, ret=1
>| kernel_alg_add():satype=3, exttype=15, alg_id=2
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[7], exttype=15, satype=3, alg_id=2, alg_ivlen=8, alg_minbits=64, alg_maxbits=64, res=0, ret=1
>| kernel_alg_add():satype=3, exttype=15, alg_id=3
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[8], exttype=15, satype=3, alg_id=3, alg_ivlen=8, alg_minbits=192, alg_maxbits=192, res=0, ret=1
>| kernel_alg_add():satype=3, exttype=15, alg_id=6
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[9], exttype=15, satype=3, alg_id=6, alg_ivlen=8, alg_minbits=40, alg_maxbits=128, res=0, ret=1
>| kernel_alg_add():satype=3, exttype=15, alg_id=7
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[10], exttype=15, satype=3, alg_id=7, alg_ivlen=8, alg_minbits=40, alg_maxbits=448, res=0, ret=1
>| kernel_alg_add():satype=3, exttype=15, alg_id=12
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[11], exttype=15, satype=3, alg_id=12, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
>| kernel_alg_add():satype=3, exttype=15, alg_id=252
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[12], exttype=15, satype=3, alg_id=252, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
>| kernel_alg_add():satype=3, exttype=15, alg_id=253
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[13], exttype=15, satype=3, alg_id=253, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
>| kernel_alg_add():satype=3, exttype=15, alg_id=13
>| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[14], exttype=15, satype=3, alg_id=13, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
>| kernel_alg_add():satype=3, exttype=15, alg_id=18
>| kernel_alg_add():satype=3, exttype=15, alg_id=19
>| kernel_alg_add():satype=3, exttype=15, alg_id=20
>| kernel_alg_add():satype=3, exttype=15, alg_id=14
>| kernel_alg_add():satype=3, exttype=15, alg_id=15
>| kernel_alg_add():satype=3, exttype=15, alg_id=16
>ike_alg_register_enc(): Activating aes_ccm_8: Ok (ret=0)
>ike_alg_add(): ERROR: Algorithm already exists
>ike_alg_register_enc(): Activating aes_ccm_12: FAILED (ret=-17)
>ike_alg_add(): ERROR: Algorithm already exists
>ike_alg_register_enc(): Activating aes_ccm_16: FAILED (ret=-17)
>ike_alg_add(): ERROR: Algorithm already exists
>ike_alg_register_enc(): Activating aes_gcm_8: FAILED (ret=-17)
>ike_alg_add(): ERROR: Algorithm already exists
>ike_alg_register_enc(): Activating aes_gcm_12: FAILED (ret=-17)
>ike_alg_add(): ERROR: Algorithm already exists
>ike_alg_register_enc(): Activating aes_gcm_16: FAILED (ret=-17)
>| 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  e8 0a 00 00
>| pfkey_get: K_SADB_REGISTER message 3
>| IPCOMP registered with kernel.
>Could not change to directory '/etc/ipsec.d/cacerts': /tmp
>Could not change to directory '/etc/ipsec.d/aacerts': /tmp
>Could not change to directory '/etc/ipsec.d/ocspcerts': /tmp
>Could not change to directory '/etc/ipsec.d/crls'
>| selinux support is enabled. 
>openswan:  could not determine enforcing mode
>| selinux: could not initialize avc. 
>| inserting event EVENT_LOG_DAILY, timeout in 9788 seconds
>| event added after event EVENT_REINIT_SECRET
>| next event EVENT_PENDING_DDNS in 60 seconds
>| 
>| *received whack message
>| alg_info_parse_str() ealg_buf=3des aalg_buf=sha1eklen=0  aklen=0
>| enum_search_prefix () calling enum_search(0x2b49ac99e580, "OAKLEY_3DES")
>| enum_search_ppfixi () calling enum_search(0x2b49ac99e580, "OAKLEY_3DES_CBC")
>| parser_alg_info_add() ealg_getbyname("3des")=5
>| enum_search_prefix () calling enum_search(0x2b49ac99e5a0, "OAKLEY_SHA1")
>Non-fips mode set in /proc/sys/crypto/fips_enabled
>| parser_alg_info_add() aalg_getbyname("sha1")=2
>| __alg_info_ike_add() ealg=5 aalg=2 modp_id=5, cnt=1
>| __alg_info_ike_add() ealg=5 aalg=2 modp_id=2, cnt=2
>| Added new connection v4 with policy PSK+ENCRYPT+IKEv2ALLOW+SAREFTRACK
>| from whack: got --esp=3des-sha1
>| alg_info_parse_str() ealg_buf=3des aalg_buf=sha1eklen=0  aklen=0
>| enum_search_prefix () calling enum_search(0x2b49ac99e440, "ESP_3DES")
>| parser_alg_info_add() ealg_getbyname("3des")=3
>| enum_search_prefix () calling enum_search(0x2b49ac998a40, "AUTH_ALGORITHM_HMAC_SHA1")
>Non-fips mode set in /proc/sys/crypto/fips_enabled
>| parser_alg_info_add() aalg_getbyname("sha1")=2
>| __alg_info_esp_add() ealg=3 aalg=2 cnt=1
>| esp string values: 3DES(3)_000-SHA1(2)_000; flags=-strict
>| ike (phase1) algorihtm values: 3DES_CBC(5)_000-SHA1(2)_000-MODP1536(5), 3DES_CBC(5)_000-SHA1(2)_000-MODP1024(2); flags=-strict
>| loopback=0 labeled_ipsec=0, policy_label=(null)
>| counting wild cards for 192.1.2.45 is 0
>| counting wild cards for 192.1.2.23 is 0
>| alg_info_addref() alg_info->ref_cnt=1
>| alg_info_addref() alg_info->ref_cnt=1
>added connection description "v4"
>| 192.1.2.45<192.1.2.45>[+S=C]...192.1.2.23<192.1.2.23>[+S=C]
>| ike_life: 3600s; ipsec_life: 28800s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0; policy: PSK+ENCRYPT+IKEv2ALLOW+SAREFTRACK
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_PENDING_DDNS in 60 seconds
>| next event EVENT_PENDING_DDNS in 60 seconds
>| 
>| *received whack message
>| alg_info_parse_str() ealg_buf=3des aalg_buf=sha1eklen=0  aklen=0
>| enum_search_prefix () calling enum_search(0x2b49ac99e580, "OAKLEY_3DES")
>| enum_search_ppfixi () calling enum_search(0x2b49ac99e580, "OAKLEY_3DES_CBC")
>| parser_alg_info_add() ealg_getbyname("3des")=5
>| enum_search_prefix () calling enum_search(0x2b49ac99e5a0, "OAKLEY_SHA1")
>Non-fips mode set in /proc/sys/crypto/fips_enabled
>| parser_alg_info_add() aalg_getbyname("sha1")=2
>| __alg_info_ike_add() ealg=5 aalg=2 modp_id=5, cnt=1
>| __alg_info_ike_add() ealg=5 aalg=2 modp_id=2, cnt=2
>| Added new connection v6 with policy PSK+ENCRYPT+IKEv2ALLOW+SAREFTRACK
>| from whack: got --esp=3des-sha1
>| alg_info_parse_str() ealg_buf=3des aalg_buf=sha1eklen=0  aklen=0
>| enum_search_prefix () calling enum_search(0x2b49ac99e440, "ESP_3DES")
>| parser_alg_info_add() ealg_getbyname("3des")=3
>| enum_search_prefix () calling enum_search(0x2b49ac998a40, "AUTH_ALGORITHM_HMAC_SHA1")
>Non-fips mode set in /proc/sys/crypto/fips_enabled
>| parser_alg_info_add() aalg_getbyname("sha1")=2
>| __alg_info_esp_add() ealg=3 aalg=2 cnt=1
>| esp string values: 3DES(3)_000-SHA1(2)_000; flags=-strict
>| ike (phase1) algorihtm values: 3DES_CBC(5)_000-SHA1(2)_000-MODP1536(5), 3DES_CBC(5)_000-SHA1(2)_000-MODP1024(2); flags=-strict
>| loopback=0 labeled_ipsec=0, policy_label=(null)
>| counting wild cards for 2001:db8:1:2::23 is 0
>| counting wild cards for 2001:db8:1:2::45 is 0
>| alg_info_addref() alg_info->ref_cnt=1
>| alg_info_addref() alg_info->ref_cnt=1
>added connection description "v6"
>| 2001:db8:1:2::23<2001:db8:1:2::23>[+S=C]...2001:db8:1:2::45<2001:db8:1:2::45>[+S=C]
>| ike_life: 3600s; ipsec_life: 28800s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0; policy: PSK+ENCRYPT+IKEv2ALLOW+SAREFTRACK
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_PENDING_DDNS in 60 seconds
>| next event EVENT_PENDING_DDNS in 60 seconds
>| 
>| *received whack message
>listening for IKE messages
>| found lo with address 127.0.0.1
>| found eth0 with address 192.0.2.254
>| found eth1 with address 192.1.2.23
>| found eth2 with address 192.9.2.23
>adding interface eth2/eth2 192.9.2.23:500
>adding interface eth1/eth1 192.1.2.23:500
>adding interface eth0/eth0 192.0.2.254:500
>adding interface lo/lo 127.0.0.1:500
>| found eth2 with address 2001:0db8:0009:0002:0000:0000:0000:0023
>| found eth1 with address 2001:0db8:0001:0002:0000:0000:0000:0023
>| found lo with address 0000:0000:0000:0000:0000:0000:0000:0001
>| found eth0 with address 2001:0db8:0000:0002:0000:0000:0000:0254
>adding interface eth0/eth0 2001:db8:0:2::254:500
>adding interface lo/lo ::1:500
>adding interface eth1/eth1 2001:db8:1:2::23:500
>adding interface eth2/eth2 2001:db8:9:2::23:500
>| connect_to_host_pair: 2001:db8:1:2::23:500 2001:db8:1:2::45:500 -> hp:none 
>| find_host_pair: comparing to 2001:db8:1:2::23:500 2001:db8:1:2::45:500 
>| connect_to_host_pair: 192.1.2.23:500 192.1.2.45:500 -> hp:none 
>loading secrets from "/etc/ipsec.secrets"
>| id type added to secret(0x2b49aca0d130) PPK_PSK: 192.1.2.45
>| id type added to secret(0x2b49aca0d130) PPK_PSK: 192.1.2.23
>| Processing PSK at line 2: passed
>| id type added to secret(0x2b49aca0dc70) PPK_PSK: 2001:db8:1:2::23
>| id type added to secret(0x2b49aca0dc70) PPK_PSK: 2001:db8:1:2::45
>| Processing PSK at line 2: passed
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_PENDING_DDNS in 60 seconds
>| next event EVENT_PENDING_DDNS in 60 seconds
>| 
>| *received whack message
>| processing connection v4
>| route owner of "v4" unrouted: NULL; eroute owner: NULL
>| could_route called for v4 (kind=CK_PERMANENT)
>| route owner of "v4" unrouted: NULL; eroute owner: NULL
>| route_and_eroute with c: v4 (next: none) ero:null esr:{(nil)} ro:null rosr:{(nil)} and state: 0
>| request to add a prospective erouted policy with netkey kernel --- experimental
>| route_and_eroute: firewall_notified: true
>| command executing prepare-host
>| executing prepare-host: 2>&1 PLUTO_VERB='prepare-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='v4' PLUTO_INTERFACE='eth1' PLUTO_NEXT_HOP='192.1.2.45' PLUTO_ME='192.1.2.23' PLUTO_MY_ID='192.1.2.23' PLUTO_MY_CLIENT='192.1.2.23/32' PLUTO_MY_CLIENT_NET='192.1.2.23' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='192.1.2.45' PLUTO_PEER_ID='192.1.2.45' PLUTO_PEER_CLIENT='192.1.2.45/32' PLUTO_PEER_CLIENT_NET='192.1.2.45' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+IKEv2ALLOW+SAREFTRACK'   PLUTO_IS_PEER_CISCO='0' PLUTO_CISCO_DNS_INFO='' PLUTO_CISCO_DOMAIN_INFO='' PLUTO_PEER_BANNER='' ipsec _updown
>| popen(): cmd is 724 chars long
>| cmd(   0):2>&1 PLUTO_VERB='prepare-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='v4' PLUTO_I:
>| cmd(  80):NTERFACE='eth1' PLUTO_NEXT_HOP='192.1.2.45' PLUTO_ME='192.1.2.23' PLUTO_MY_ID='1:
>| cmd( 160):92.1.2.23' PLUTO_MY_CLIENT='192.1.2.23/32' PLUTO_MY_CLIENT_NET='192.1.2.23' PLUT:
>| cmd( 240):O_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO:
>| cmd( 320):_PEER='192.1.2.45' PLUTO_PEER_ID='192.1.2.45' PLUTO_PEER_CLIENT='192.1.2.45/32' :
>| cmd( 400):PLUTO_PEER_CLIENT_NET='192.1.2.45' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUT:
>| cmd( 480):O_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey'  P:
>| cmd( 560):LUTO_CONN_POLICY='PSK+ENCRYPT+IKEv2ALLOW+SAREFTRACK'   PLUTO_IS_PEER_CISCO='0' P:
>| cmd( 640):LUTO_CISCO_DNS_INFO='' PLUTO_CISCO_DOMAIN_INFO='' PLUTO_PEER_BANNER='' ipsec _up:
>| cmd( 720):down:
>| command executing route-host
>| executing route-host: 2>&1 PLUTO_VERB='route-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='v4' PLUTO_INTERFACE='eth1' PLUTO_NEXT_HOP='192.1.2.45' PLUTO_ME='192.1.2.23' PLUTO_MY_ID='192.1.2.23' PLUTO_MY_CLIENT='192.1.2.23/32' PLUTO_MY_CLIENT_NET='192.1.2.23' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='192.1.2.45' PLUTO_PEER_ID='192.1.2.45' PLUTO_PEER_CLIENT='192.1.2.45/32' PLUTO_PEER_CLIENT_NET='192.1.2.45' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+IKEv2ALLOW+SAREFTRACK'   PLUTO_IS_PEER_CISCO='0' PLUTO_CISCO_DNS_INFO='' PLUTO_CISCO_DOMAIN_INFO='' PLUTO_PEER_BANNER='' ipsec _updown
>| popen(): cmd is 722 chars long
>| cmd(   0):2>&1 PLUTO_VERB='route-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='v4' PLUTO_INT:
>| cmd(  80):ERFACE='eth1' PLUTO_NEXT_HOP='192.1.2.45' PLUTO_ME='192.1.2.23' PLUTO_MY_ID='192:
>| cmd( 160):.1.2.23' PLUTO_MY_CLIENT='192.1.2.23/32' PLUTO_MY_CLIENT_NET='192.1.2.23' PLUTO_:
>| cmd( 240):MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_P:
>| cmd( 320):EER='192.1.2.45' PLUTO_PEER_ID='192.1.2.45' PLUTO_PEER_CLIENT='192.1.2.45/32' PL:
>| cmd( 400):UTO_PEER_CLIENT_NET='192.1.2.45' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_:
>| cmd( 480):PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey'  PLU:
>| cmd( 560):TO_CONN_POLICY='PSK+ENCRYPT+IKEv2ALLOW+SAREFTRACK'   PLUTO_IS_PEER_CISCO='0' PLU:
>| cmd( 640):TO_CISCO_DNS_INFO='' PLUTO_CISCO_DOMAIN_INFO='' PLUTO_PEER_BANNER='' ipsec _updo:
>| cmd( 720):wn:
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_PENDING_DDNS in 60 seconds
>| next event EVENT_PENDING_DDNS in 60 seconds
>| 
>| *received whack message
>| processing connection v6
>| route owner of "v6" unrouted: NULL; eroute owner: NULL
>| could_route called for v6 (kind=CK_PERMANENT)
>| route owner of "v6" unrouted: NULL; eroute owner: NULL
>| route_and_eroute with c: v6 (next: none) ero:null esr:{(nil)} ro:null rosr:{(nil)} and state: 0
>| request to add a prospective erouted policy with netkey kernel --- experimental
>| route_and_eroute: firewall_notified: true
>| command executing prepare-host-v6
>| executing prepare-host-v6: 2>&1 PLUTO_VERB='prepare-host-v6' PLUTO_VERSION='2.0' PLUTO_CONNECTION='v6' PLUTO_INTERFACE='eth1' PLUTO_NEXT_HOP='2001:db8:1:2::45' PLUTO_ME='2001:db8:1:2::23' PLUTO_MY_ID='2001:db8:1:2::23' PLUTO_MY_CLIENT='2001:db8:1:2::23/128' PLUTO_MY_CLIENT_NET='2001:db8:1:2::23' PLUTO_MY_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='2001:db8:1:2::45' PLUTO_PEER_ID='2001:db8:1:2::45' PLUTO_PEER_CLIENT='2001:db8:1:2::45/128' PLUTO_PEER_CLIENT_NET='2001:db8:1:2::45' 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_CONN_POLICY='PSK+ENCRYPT+IKEv2ALLOW+SAREFTRACK'   PLUTO_IS_PEER_CISCO='0' PLUTO_CISCO_DNS_INFO='' PLUTO_CISCO_DOMAIN_INFO='' PLUTO_PEER_BANNER='' ipsec _updown
>| popen(): cmd is 831 chars long
>| cmd(   0):2>&1 PLUTO_VERB='prepare-host-v6' PLUTO_VERSION='2.0' PLUTO_CONNECTION='v6' PLUT:
>| cmd(  80):O_INTERFACE='eth1' PLUTO_NEXT_HOP='2001:db8:1:2::45' PLUTO_ME='2001:db8:1:2::23':
>| cmd( 160): PLUTO_MY_ID='2001:db8:1:2::23' PLUTO_MY_CLIENT='2001:db8:1:2::23/128' PLUTO_MY_:
>| cmd( 240):CLIENT_NET='2001:db8:1:2::23' PLUTO_MY_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:fff:
>| cmd( 320):f:ffff:ffff' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='2001:db8:1:2::4:
>| cmd( 400):5' PLUTO_PEER_ID='2001:db8:1:2::45' PLUTO_PEER_CLIENT='2001:db8:1:2::45/128' PLU:
>| cmd( 480):TO_PEER_CLIENT_NET='2001:db8:1:2::45' PLUTO_PEER_CLIENT_MASK='ffff:ffff:ffff:fff:
>| cmd( 560):f:ffff:ffff:ffff:ffff' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA:
>| cmd( 640):='' PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+IKEv2ALLOW+SAREFTRACK' :
>| cmd( 720):  PLUTO_IS_PEER_CISCO='0' PLUTO_CISCO_DNS_INFO='' PLUTO_CISCO_DOMAIN_INFO='' PLU:
>| cmd( 800):TO_PEER_BANNER='' ipsec _updown:
>| command executing route-host-v6
>| executing route-host-v6: 2>&1 PLUTO_VERB='route-host-v6' PLUTO_VERSION='2.0' PLUTO_CONNECTION='v6' PLUTO_INTERFACE='eth1' PLUTO_NEXT_HOP='2001:db8:1:2::45' PLUTO_ME='2001:db8:1:2::23' PLUTO_MY_ID='2001:db8:1:2::23' PLUTO_MY_CLIENT='2001:db8:1:2::23/128' PLUTO_MY_CLIENT_NET='2001:db8:1:2::23' PLUTO_MY_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='2001:db8:1:2::45' PLUTO_PEER_ID='2001:db8:1:2::45' PLUTO_PEER_CLIENT='2001:db8:1:2::45/128' PLUTO_PEER_CLIENT_NET='2001:db8:1:2::45' 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_CONN_POLICY='PSK+ENCRYPT+IKEv2ALLOW+SAREFTRACK'   PLUTO_IS_PEER_CISCO='0' PLUTO_CISCO_DNS_INFO='' PLUTO_CISCO_DOMAIN_INFO='' PLUTO_PEER_BANNER='' ipsec _updown
>| popen(): cmd is 829 chars long
>| cmd(   0):2>&1 PLUTO_VERB='route-host-v6' PLUTO_VERSION='2.0' PLUTO_CONNECTION='v6' PLUTO_:
>| cmd(  80):INTERFACE='eth1' PLUTO_NEXT_HOP='2001:db8:1:2::45' PLUTO_ME='2001:db8:1:2::23' P:
>| cmd( 160):LUTO_MY_ID='2001:db8:1:2::23' PLUTO_MY_CLIENT='2001:db8:1:2::23/128' PLUTO_MY_CL:
>| cmd( 240):IENT_NET='2001:db8:1:2::23' PLUTO_MY_CLIENT_MASK='ffff:ffff:ffff:ffff:ffff:ffff::
>| cmd( 320):ffff:ffff' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='2001:db8:1:2::45':
>| cmd( 400): PLUTO_PEER_ID='2001:db8:1:2::45' PLUTO_PEER_CLIENT='2001:db8:1:2::45/128' PLUTO:
>| cmd( 480):_PEER_CLIENT_NET='2001:db8:1:2::45' PLUTO_PEER_CLIENT_MASK='ffff:ffff:ffff:ffff::
>| cmd( 560):ffff:ffff:ffff:ffff' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA=':
>| cmd( 640):' PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+IKEv2ALLOW+SAREFTRACK'   :
>| cmd( 720):PLUTO_IS_PEER_CISCO='0' PLUTO_CISCO_DNS_INFO='' PLUTO_CISCO_DOMAIN_INFO='' PLUTO:
>| cmd( 800):_PEER_BANNER='' ipsec _updown:
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_PENDING_DDNS in 60 seconds
>| next event EVENT_PENDING_DDNS in 60 seconds
>| 
>| *received kernel message
>| netlink_get: XFRM_MSG_ACQUIRE message
>| xfrm netlink msg len 364
>| xfrm:nlmsghdr= 16
>| xfrm:acquire= 280
>| xfrm:rtattr= 4
>| rtattr len= 68
>| xfrm: found XFRMA_TMPL
>| xfrm: did not found XFRMA_SEC_CTX, trying next one
>| xfrm: rta->len=68
>| xfrm: remaining=0 , rta->len = 28274
>| xfrm: not found anything, seems wierd
>| xfrm: not found sec ctx still, perhaps not a labeled ipsec connection
>| add bare shunt 0x2b49aca0d9b0 192.1.2.23/32:3 --1--> 192.1.2.45/32:10 => %hold 0    %acquire-netlink
>| received security label string: 
>initiate on demand from 192.1.2.23:3 to 192.1.2.45:10 proto=1 state: fos_start because: acquire
>| find_connection: looking for policy for connection: 192.1.2.23:1/3 -> 192.1.2.45:1/10
>| find_connection: conn "v4" has compatible peers: 192.1.2.23/32 -> 192.1.2.45/32 [pri: 16842760]
>| find_connection: comparing best "v4" [pri:16842760]{0x2b49aca0a480} (child none) to "v4" [pri:16842760]{0x2b49aca0a480} (child none)
>| find_connection: concluding with "v4" [pri:16842760]{0x2b49aca0a480} kind=CK_PERMANENT
>| assign hold, routing was prospective erouted, needs to be erouted HOLD
>| delete bare shunt: null pointer
>| creating state object #1 at 0x2b49aca0de00
>| processing connection v4
>| ICOOKIE:  3f 38 80 4f  d3 db a5 9f
>| RCOOKIE:  00 00 00 00  00 00 00 00
>| state hash entry 2
>| inserting state object #1 on chain 2
>| inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #1
>| event added at head of queue
>| processing connection v4
>| Queuing pending Quick Mode with 192.1.2.45 "v4"
>"v4" #1: initiating Main Mode
>| **emit ISAKMP Message:
>|    initiator cookie:
>|   3f 38 80 4f  d3 db a5 9f
>|    responder cookie:
>|   00 00 00 00  00 00 00 00
>|    next payload type: ISAKMP_NEXT_SA
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_IDPROT
>|    flags: none
>|    message ID:  00 00 00 00
>| ***emit ISAKMP Security Association Payload:
>|    next payload type: ISAKMP_NEXT_VID
>|    DOI: ISAKMP_DOI_IPSEC
>| ****emit IPsec DOI SIT:
>|    IPsec DOI SIT: SIT_IDENTITY_ONLY
>| out_sa pcn: 0 has 1 valid proposals
>| out_sa pcn: 0 pn: 0<1 valid_count: 1 trans_cnt: 2
>| ****emit ISAKMP Proposal Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    proposal number: 0
>|    protocol ID: PROTO_ISAKMP
>|    SPI size: 0
>|    number of transforms: 2
>| *****emit ISAKMP Transform Payload (ISAKMP):
>|    next payload type: ISAKMP_NEXT_T
>|    transform number: 0
>|    transform ID: KEY_IKE
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_LIFE_TYPE
>|    length/value: 1
>|     [1 is OAKLEY_LIFE_SECONDS]
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_LIFE_DURATION
>|    length/value: 3600
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_ENCRYPTION_ALGORITHM
>|    length/value: 5
>|     [5 is OAKLEY_3DES_CBC]
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_HASH_ALGORITHM
>|    length/value: 2
>|     [2 is OAKLEY_SHA1]
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_AUTHENTICATION_METHOD
>|    length/value: 1
>|     [1 is OAKLEY_PRESHARED_KEY]
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_GROUP_DESCRIPTION
>|    length/value: 5
>|     [5 is OAKLEY_GROUP_MODP1536]
>| emitting length of ISAKMP Transform Payload (ISAKMP): 32
>| *****emit ISAKMP Transform Payload (ISAKMP):
>|    next payload type: ISAKMP_NEXT_NONE
>|    transform number: 1
>|    transform ID: KEY_IKE
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_LIFE_TYPE
>|    length/value: 1
>|     [1 is OAKLEY_LIFE_SECONDS]
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_LIFE_DURATION
>|    length/value: 3600
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_ENCRYPTION_ALGORITHM
>|    length/value: 5
>|     [5 is OAKLEY_3DES_CBC]
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_HASH_ALGORITHM
>|    length/value: 2
>|     [2 is OAKLEY_SHA1]
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_AUTHENTICATION_METHOD
>|    length/value: 1
>|     [1 is OAKLEY_PRESHARED_KEY]
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_GROUP_DESCRIPTION
>|    length/value: 2
>|     [2 is OAKLEY_GROUP_MODP1024]
>| emitting length of ISAKMP Transform Payload (ISAKMP): 32
>| emitting length of ISAKMP Proposal Payload: 72
>| emitting length of ISAKMP Security Association Payload: 84
>| ***emit ISAKMP Vendor ID Payload:
>|    next payload type: ISAKMP_NEXT_VID
>| emitting 12 raw bytes of Vendor ID into ISAKMP Vendor ID Payload
>| Vendor ID  4f 45 68 79  4c 64 41 43  65 63 66 61
>| emitting length of ISAKMP Vendor ID Payload: 16
>| out_vendorid(): sending [Dead Peer Detection]
>| ***emit ISAKMP Vendor ID Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>| emitting 16 raw bytes of V_ID into ISAKMP Vendor ID Payload
>| V_ID  af ca d7 13  68 a1 f1 c9  6b 86 96 fc  77 57 01 00
>| emitting length of ISAKMP Vendor ID Payload: 20
>| nat traversal enabled: 0
>| emitting length of ISAKMP Message: 148
>| sending 148 bytes for main_outI1 through eth1:500 to 192.1.2.45:500 (using #1)
>|   3f 38 80 4f  d3 db a5 9f  00 00 00 00  00 00 00 00
>|   01 10 02 00  00 00 00 00  00 00 00 94  0d 00 00 54
>|   00 00 00 01  00 00 00 01  00 00 00 48  00 01 00 02
>|   03 00 00 20  00 01 00 00  80 0b 00 01  80 0c 0e 10
>|   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 05
>|   00 00 00 20  01 01 00 00  80 0b 00 01  80 0c 0e 10
>|   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 02
>|   0d 00 00 10  4f 45 68 79  4c 64 41 43  65 63 66 61
>|   00 00 00 14  af ca d7 13  68 a1 f1 c9  6b 86 96 fc
>|   77 57 01 00
>| deleting event for #1
>| inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
>| event added at head of queue
>| delete bare shunt 0x2b49aca0d9b0 192.1.2.23/32:3 --1--> 192.1.2.45/32:10 => %hold 0    %acquire-netlink
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 10 seconds for #1
>| next event EVENT_RETRANSMIT in 10 seconds for #1
>| 
>| *received whack message
>| processing connection v4
>| kernel_alg_db_new() initial trans_cnt=90
>| 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
>| Queuing pending Quick Mode with 192.1.2.45 "v4"
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 10 seconds for #1
>| next event EVENT_RETRANSMIT in 10 seconds for #1
>| 
>| *received 116 bytes from 192.1.2.45:500 on eth1 (port=500)
>|   3f 38 80 4f  d3 db a5 9f  c2 36 4a 02  d0 15 cc 47
>|   01 10 02 00  00 00 00 00  00 00 00 74  0d 00 00 34
>|   00 00 00 01  00 00 00 01  00 00 00 28  00 01 00 01
>|   00 00 00 20  00 01 00 00  80 0b 00 01  80 0c 0e 10
>|   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 05
>|   0d 00 00 10  4f 45 68 79  4c 64 41 43  65 63 66 61
>|   00 00 00 14  af ca d7 13  68 a1 f1 c9  6b 86 96 fc
>|   77 57 01 00
>| **parse ISAKMP Message:
>|    initiator cookie:
>|   3f 38 80 4f  d3 db a5 9f
>|    responder cookie:
>|   c2 36 4a 02  d0 15 cc 47
>|    next payload type: ISAKMP_NEXT_SA
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_IDPROT
>|    flags: none
>|    message ID:  00 00 00 00
>|    length: 116
>|  processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
>| ICOOKIE:  3f 38 80 4f  d3 db a5 9f
>| RCOOKIE:  c2 36 4a 02  d0 15 cc 47
>| state hash entry 30
>| v1 state object not found
>| ICOOKIE:  3f 38 80 4f  d3 db a5 9f
>| RCOOKIE:  00 00 00 00  00 00 00 00
>| state hash entry 2
>| v1 peer and cookies match on #1, provided msgid 00000000 vs 00000000
>| v1 state object #1 found, in STATE_MAIN_I1
>| processing connection v4
>| got payload 0x2(ISAKMP_NEXT_SA) needed: 0x2 opt: 0x2080
>| ***parse ISAKMP Security Association Payload:
>|    next payload type: ISAKMP_NEXT_VID
>|    length: 52
>|    DOI: ISAKMP_DOI_IPSEC
>| got payload 0x2000(ISAKMP_NEXT_VID) needed: 0x0 opt: 0x2080
>| ***parse ISAKMP Vendor ID Payload:
>|    next payload type: ISAKMP_NEXT_VID
>|    length: 16
>| got payload 0x2000(ISAKMP_NEXT_VID) needed: 0x0 opt: 0x2080
>| ***parse ISAKMP Vendor ID Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 20
>"v4" #1: received Vendor ID payload [Openswan (this version) 2.6.32 ]
>"v4" #1: received Vendor ID payload [Dead Peer Detection]
>| ****parse IPsec DOI SIT:
>|    IPsec DOI SIT: SIT_IDENTITY_ONLY
>| ****parse ISAKMP Proposal Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 40
>|    proposal number: 0
>|    protocol ID: PROTO_ISAKMP
>|    SPI size: 0
>|    number of transforms: 1
>| *****parse ISAKMP Transform Payload (ISAKMP):
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 32
>|    transform number: 0
>|    transform ID: KEY_IKE
>| ******parse ISAKMP Oakley attribute:
>|    af+type: OAKLEY_LIFE_TYPE
>|    length/value: 1
>|    [1 is OAKLEY_LIFE_SECONDS]
>| ******parse ISAKMP Oakley attribute:
>|    af+type: OAKLEY_LIFE_DURATION
>|    length/value: 3600
>| ******parse ISAKMP Oakley attribute:
>|    af+type: OAKLEY_ENCRYPTION_ALGORITHM
>|    length/value: 5
>|    [5 is OAKLEY_3DES_CBC]
>| ike_alg_enc_ok(ealg=5,key_len=0): blocksize=8, keyminlen=192, keydeflen=192, keymaxlen=192, ret=1
>| ******parse ISAKMP Oakley attribute:
>|    af+type: OAKLEY_HASH_ALGORITHM
>|    length/value: 2
>|    [2 is OAKLEY_SHA1]
>| ******parse ISAKMP Oakley attribute:
>|    af+type: OAKLEY_AUTHENTICATION_METHOD
>|    length/value: 1
>|    [1 is OAKLEY_PRESHARED_KEY]
>| started looking for secret for 192.1.2.23->192.1.2.45 of kind PPK_PSK
>| actually looking for secret for 192.1.2.23->192.1.2.45 of kind PPK_PSK
>| line 2: key type PPK_PSK(192.1.2.23) to type PPK_PSK 
>| 1: compared key 2001:db8:1:2::45 to 192.1.2.23 / 192.1.2.45 -> 0
>| 2: compared key 2001:db8:1:2::23 to 192.1.2.23 / 192.1.2.45 -> 0
>| line 2: match=0 
>| line 1: key type PPK_PSK(192.1.2.23) to type PPK_PSK 
>| 1: compared key 192.1.2.23 to 192.1.2.23 / 192.1.2.45 -> 8
>| 2: compared key 192.1.2.45 to 192.1.2.23 / 192.1.2.45 -> 12
>| line 1: match=12 
>| best_match 0>12 best=0x2b49aca0d130 (line=1)
>| concluding with best_match=12 best=0x2b49aca0d130 (lineno=1)
>| ******parse ISAKMP Oakley attribute:
>|    af+type: OAKLEY_GROUP_DESCRIPTION
>|    length/value: 5
>|    [5 is OAKLEY_GROUP_MODP1536]
>| Oakley Transform 0 accepted
>| sender checking NAT-t: 0 and 0
>| 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
>| asking helper 0 to do build_kenonce op on seq: 1 (len=2776, pcw_work=1)
>| helper 0 read 2768+4/2776 bytes fd: 10
>| helper 0 doing build_kenonce op 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 e4 5b 3d  c2 00 7c b8  a1 63 bf 05
>|   98 da 48 36  1c 55 d3 9a  69 16 3f a8  fd 24 cf 5f
>|   83 65 5d 23  dc a3 ad 96  1c 62 f3 56  20 85 52 bb
>|   9e d5 29 07  70 96 96 6d  67 0c 35 4e  4a bc 98 04
>|   f1 74 6c 08  ca 23 73 27  ff ff ff ff  ff ff ff ff
>| NSS: Value of base:
>|   02
>| crypto helper write of request: cnt=2776<wlen=2776.  
>| deleting event for #1
>| inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #1
>| event added after event EVENT_PENDING_PHASE2
>| peer supports dpd
>| complete state transition with STF_SUSPEND
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_PENDING_DDNS in 60 seconds
>| next event EVENT_PENDING_DDNS in 60 seconds
>| 
>| *received kernel message
>| netlink_get: XFRM_MSG_ACQUIRE message
>| xfrm netlink msg len 364
>| xfrm:nlmsghdr= 16
>| xfrm:acquire= 280
>| xfrm:rtattr= 4
>| rtattr len= 68
>| xfrm: found XFRMA_TMPL
>| xfrm: did not found XFRMA_SEC_CTX, trying next one
>| xfrm: rta->len=68
>| xfrm: remaining=0 , rta->len = 28274
>| xfrm: not found anything, seems wierd
>| xfrm: not found sec ctx still, perhaps not a labeled ipsec connection
>| add bare shunt 0x2b49aca14580 2001:db8:1:2::23/128:136 --58--> 2001:db8:1:2::45/128:0 => %hold 0    %acquire-netlink
>| received security label string: 
>initiate on demand from 2001:db8:1:2::23:136 to 2001:db8:1:2::45:0 proto=58 state: fos_start because: acquire
>| find_connection: looking for policy for connection: 2001:db8:1:2::23:58/136 -> 2001:db8:1:2::45:58/0
>| find_connection: conn "v6" has compatible peers: 2001:db8:1:2::23/128 -> 2001:db8:1:2::45/128 [pri: 67371018]
>| find_connection: comparing best "v6" [pri:67371018]{0x2b49aca0bb00} (child none) to "v6" [pri:67371018]{0x2b49aca0bb00} (child none)
>| find_connection: concluding with "v6" [pri:67371018]{0x2b49aca0bb00} kind=CK_PERMANENT
>| assign hold, routing was prospective erouted, needs to be erouted HOLD
>| delete bare shunt: null pointer
>| creating state object #2 at 0x2b49aca14620
>| NSS: generated dh priv and pub keys: 192 
>| NSS: Local DH secret:
>|   00 5e a1 ac  49 2b 00 00
>| NSS: Public DH value sent(computed in NSS):
>|   d2 15 21 87  31 47 8f 4a  b3 e3 0c 96  ca d2 68 be
>|   f1 73 3f 27  ca fb 38 8b  ea 66 1b f0  7c b3 33 92
>|   79 bb 9f e5  3a a5 06 21  11 42 96 42  27 d3 1c 2c
>|   a6 ff a1 ed  3b 1f a0 b9  77 80 27 70  49 ad 28 e5
>|   7f ae c3 aa  43 15 de 75  0f 73 ba dc  27 40 d5 5e
>|   6b e5 09 8d  ce 55 61 12  3d e9 a8 d2  1c 4f 69 85
>|   5d 4f ca 87  16 12 bf 3c  b8 1e eb 2e  2d ae d5 2e
>|   8e 13 c2 04  e0 4a 99 87  10 48 8d b6  50 3a 7f 70
>|   d8 0e f6 a4  2a b1 15 af  43 59 1e 7f  c5 fe 4b f2
>|   45 97 48 c3  cb 8c f5 41  b8 cd 16 cd  85 44 8e 60
>|   2a 88 f6 7b  b5 23 1d b8  ea 83 c9 3a  c7 3a 1d 21
>|   e9 57 3c a2  58 8a 48 88  00 d8 54 5a  be 0f b4 c7
>| NSS: Local DH public value (pointer):
>|   f0 55 a1 ac  49 2b 00 00
>| Generated nonce:
>|   3f 70 89 5a  2d f4 11 32  47 a5 ed 11  cf a6 a2 92
>| processing connection v6
>| ICOOKIE:  7f 70 da 29  ca d1 bc bf
>| RCOOKIE:  00 00 00 00  00 00 00 00
>| state hash entry 18
>| inserting state object #2 on chain 18
>| inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #2
>| event added at head of queue
>| processing connection v6
>| Queuing pending Quick Mode with 2001:db8:1:2::45 "v6"
>"v6" #2: initiating Main Mode
>| **emit ISAKMP Message:
>|    initiator cookie:
>|   7f 70 da 29  ca d1 bc bf
>|    responder cookie:
>|   00 00 00 00  00 00 00 00
>|    next payload type: ISAKMP_NEXT_SA
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_IDPROT
>|    flags: none
>|    message ID:  00 00 00 00
>| ***emit ISAKMP Security Association Payload:
>|    next payload type: ISAKMP_NEXT_VID
>|    DOI: ISAKMP_DOI_IPSEC
>| ****emit IPsec DOI SIT:
>|    IPsec DOI SIT: SIT_IDENTITY_ONLY
>| out_sa pcn: 0 has 1 valid proposals
>| out_sa pcn: 0 pn: 0<1 valid_count: 1 trans_cnt: 2
>| ****emit ISAKMP Proposal Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    proposal number: 0
>|    protocol ID: PROTO_ISAKMP
>|    SPI size: 0
>|    number of transforms: 2
>| *****emit ISAKMP Transform Payload (ISAKMP):
>|    next payload type: ISAKMP_NEXT_T
>|    transform number: 0
>|    transform ID: KEY_IKE
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_LIFE_TYPE
>|    length/value: 1
>|     [1 is OAKLEY_LIFE_SECONDS]
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_LIFE_DURATION
>|    length/value: 3600
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_ENCRYPTION_ALGORITHM
>|    length/value: 5
>|     [5 is OAKLEY_3DES_CBC]
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_HASH_ALGORITHM
>|    length/value: 2
>|     [2 is OAKLEY_SHA1]
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_AUTHENTICATION_METHOD
>|    length/value: 1
>|     [1 is OAKLEY_PRESHARED_KEY]
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_GROUP_DESCRIPTION
>|    length/value: 5
>|     [5 is OAKLEY_GROUP_MODP1536]
>| emitting length of ISAKMP Transform Payload (ISAKMP): 32
>| *****emit ISAKMP Transform Payload (ISAKMP):
>|    next payload type: ISAKMP_NEXT_NONE
>|    transform number: 1
>|    transform ID: KEY_IKE
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_LIFE_TYPE
>|    length/value: 1
>|     [1 is OAKLEY_LIFE_SECONDS]
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_LIFE_DURATION
>|    length/value: 3600
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_ENCRYPTION_ALGORITHM
>|    length/value: 5
>|     [5 is OAKLEY_3DES_CBC]
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_HASH_ALGORITHM
>|    length/value: 2
>|     [2 is OAKLEY_SHA1]
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_AUTHENTICATION_METHOD
>|    length/value: 1
>|     [1 is OAKLEY_PRESHARED_KEY]
>| ******emit ISAKMP Oakley attribute:
>|    af+type: OAKLEY_GROUP_DESCRIPTION
>|    length/value: 2
>|     [2 is OAKLEY_GROUP_MODP1024]
>| emitting length of ISAKMP Transform Payload (ISAKMP): 32
>| emitting length of ISAKMP Proposal Payload: 72
>| emitting length of ISAKMP Security Association Payload: 84
>| ***emit ISAKMP Vendor ID Payload:
>|    next payload type: ISAKMP_NEXT_VID
>| emitting 12 raw bytes of Vendor ID into ISAKMP Vendor ID Payload
>| Vendor ID  4f 45 68 79  4c 64 41 43  65 63 66 61
>| emitting length of ISAKMP Vendor ID Payload: 16
>| out_vendorid(): sending [Dead Peer Detection]
>| ***emit ISAKMP Vendor ID Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>| emitting 16 raw bytes of V_ID into ISAKMP Vendor ID Payload
>| V_ID  af ca d7 13  68 a1 f1 c9  6b 86 96 fc  77 57 01 00
>| emitting length of ISAKMP Vendor ID Payload: 20
>| nat traversal enabled: 0
>| emitting length of ISAKMP Message: 148
>| sending 148 bytes for main_outI1 through eth1:500 to 2001:db8:1:2::45:500 (using #2)
>|   7f 70 da 29  ca d1 bc bf  00 00 00 00  00 00 00 00
>|   01 10 02 00  00 00 00 00  00 00 00 94  0d 00 00 54
>|   00 00 00 01  00 00 00 01  00 00 00 48  00 01 00 02
>|   03 00 00 20  00 01 00 00  80 0b 00 01  80 0c 0e 10
>|   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 05
>|   00 00 00 20  01 01 00 00  80 0b 00 01  80 0c 0e 10
>|   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 02
>|   0d 00 00 10  4f 45 68 79  4c 64 41 43  65 63 66 61
>|   00 00 00 14  af ca d7 13  68 a1 f1 c9  6b 86 96 fc
>|   77 57 01 00
>| deleting event for #2
>| inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #2
>| event added at head of queue
>| delete bare shunt 0x2b49aca14580 2001:db8:1:2::23/128:136 --58--> 2001:db8:1:2::45/128:0 => %hold 0    %acquire-netlink
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 10 seconds for #2
>| next event EVENT_RETRANSMIT in 10 seconds for #2
>| 
>| helper 0 has finished work (cnt now 1)
>| helper 0 replies to id: q#1
>| calling callback function 0x2b49ac6d87b0
>| main inR1_outI2: calculated ke+nonce, sending I2
>| processing connection v4
>| **emit ISAKMP Message:
>|    initiator cookie:
>|   3f 38 80 4f  d3 db a5 9f
>|    responder cookie:
>|   c2 36 4a 02  d0 15 cc 47
>|    next payload type: ISAKMP_NEXT_KE
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_IDPROT
>|    flags: none
>|    message ID:  00 00 00 00
>| saving DH priv (local secret) and pub key into state struc
>| ***emit ISAKMP Key Exchange Payload:
>|    next payload type: ISAKMP_NEXT_NONCE
>| emitting 192 raw bytes of keyex value into ISAKMP Key Exchange Payload
>| keyex value  d2 15 21 87  31 47 8f 4a  b3 e3 0c 96  ca d2 68 be
>| keyex value  f1 73 3f 27  ca fb 38 8b  ea 66 1b f0  7c b3 33 92
>| keyex value  79 bb 9f e5  3a a5 06 21  11 42 96 42  27 d3 1c 2c
>| keyex value  a6 ff a1 ed  3b 1f a0 b9  77 80 27 70  49 ad 28 e5
>| keyex value  7f ae c3 aa  43 15 de 75  0f 73 ba dc  27 40 d5 5e
>| keyex value  6b e5 09 8d  ce 55 61 12  3d e9 a8 d2  1c 4f 69 85
>| keyex value  5d 4f ca 87  16 12 bf 3c  b8 1e eb 2e  2d ae d5 2e
>| keyex value  8e 13 c2 04  e0 4a 99 87  10 48 8d b6  50 3a 7f 70
>| keyex value  d8 0e f6 a4  2a b1 15 af  43 59 1e 7f  c5 fe 4b f2
>| keyex value  45 97 48 c3  cb 8c f5 41  b8 cd 16 cd  85 44 8e 60
>| keyex value  2a 88 f6 7b  b5 23 1d b8  ea 83 c9 3a  c7 3a 1d 21
>| keyex value  e9 57 3c a2  58 8a 48 88  00 d8 54 5a  be 0f b4 c7
>| emitting length of ISAKMP Key Exchange Payload: 196
>| ***emit ISAKMP Nonce Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>| emitting 16 raw bytes of Ni into ISAKMP Nonce Payload
>| Ni  3f 70 89 5a  2d f4 11 32  47 a5 ed 11  cf a6 a2 92
>| emitting length of ISAKMP Nonce Payload: 20
>| emitting length of ISAKMP Message: 244
>| ICOOKIE:  3f 38 80 4f  d3 db a5 9f
>| RCOOKIE:  00 00 00 00  00 00 00 00
>| state hash entry 2
>| ICOOKIE:  3f 38 80 4f  d3 db a5 9f
>| RCOOKIE:  c2 36 4a 02  d0 15 cc 47
>| state hash entry 30
>| inserting state object #1 on chain 30
>| complete state transition with STF_OK
>"v4" #1: transition from state STATE_MAIN_I1 to state STATE_MAIN_I2
>| deleting event for #1
>| sending reply packet to 192.1.2.45:500 (from port 500)
>| sending 244 bytes for STATE_MAIN_I1 through eth1:500 to 192.1.2.45:500 (using #1)
>|   3f 38 80 4f  d3 db a5 9f  c2 36 4a 02  d0 15 cc 47
>|   04 10 02 00  00 00 00 00  00 00 00 f4  0a 00 00 c4
>|   d2 15 21 87  31 47 8f 4a  b3 e3 0c 96  ca d2 68 be
>|   f1 73 3f 27  ca fb 38 8b  ea 66 1b f0  7c b3 33 92
>|   79 bb 9f e5  3a a5 06 21  11 42 96 42  27 d3 1c 2c
>|   a6 ff a1 ed  3b 1f a0 b9  77 80 27 70  49 ad 28 e5
>|   7f ae c3 aa  43 15 de 75  0f 73 ba dc  27 40 d5 5e
>|   6b e5 09 8d  ce 55 61 12  3d e9 a8 d2  1c 4f 69 85
>|   5d 4f ca 87  16 12 bf 3c  b8 1e eb 2e  2d ae d5 2e
>|   8e 13 c2 04  e0 4a 99 87  10 48 8d b6  50 3a 7f 70
>|   d8 0e f6 a4  2a b1 15 af  43 59 1e 7f  c5 fe 4b f2
>|   45 97 48 c3  cb 8c f5 41  b8 cd 16 cd  85 44 8e 60
>|   2a 88 f6 7b  b5 23 1d b8  ea 83 c9 3a  c7 3a 1d 21
>|   e9 57 3c a2  58 8a 48 88  00 d8 54 5a  be 0f b4 c7
>|   00 00 00 14  3f 70 89 5a  2d f4 11 32  47 a5 ed 11
>|   cf a6 a2 92
>| inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
>| event added at head of queue
>"v4" #1: STATE_MAIN_I2: sent MI2, expecting MR2
>| modecfg pull: noquirk policy:push not-client
>| phase 1 is done, looking for phase 2 to unpend
>| * processed 1 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 10 seconds for #1
>| next event EVENT_RETRANSMIT in 10 seconds for #1
>| 
>| *received whack message
>| processing connection v6
>| kernel_alg_db_new() initial trans_cnt=90
>| 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
>| Queuing pending Quick Mode with 2001:db8:1:2::45 "v6"
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 10 seconds for #1
>| next event EVENT_RETRANSMIT in 10 seconds for #1
>| 
>| *received 244 bytes from 192.1.2.45:500 on eth1 (port=500)
>|   3f 38 80 4f  d3 db a5 9f  c2 36 4a 02  d0 15 cc 47
>|   04 10 02 00  00 00 00 00  00 00 00 f4  0a 00 00 c4
>|   ba a0 2e e7  cc a1 f7 df  a3 7f 7b f0  d8 ea d8 54
>|   24 11 59 7a  2b 0b a7 4b  95 ba 40 ee  9a 4d 86 98
>|   6a 87 d0 67  60 5a 88 dc  63 88 63 b9  4f be 71 32
>|   72 0a b4 b8  ea b1 a2 de  9b 16 01 85  c9 7a af 50
>|   54 9f 30 2a  6a fa b6 27  8a 08 21 7e  47 7d 33 c0
>|   5b 92 dd 83  ac a3 6e f2  c7 0c a1 8d  8c e9 4b 0a
>|   8c b7 b4 8e  74 2e 48 3f  53 6b 36 7b  ec 04 c3 84
>|   80 0a 9f 9c  db ea 10 b0  59 b4 b1 d3  99 05 67 b0
>|   4a 06 26 43  81 bc 56 f4  ef 0a 88 76  fd 05 8d 8f
>|   e9 8e ea 40  70 f0 2f db  30 40 12 33  79 69 a6 aa
>|   ff d5 da 45  3d 3c fc 64  80 52 c6 f0  fc d1 22 51
>|   ad 74 97 28  5f c4 0e 56  13 bd 19 44  df 79 54 08
>|   00 00 00 14  20 85 80 f4  ba 94 6c 3b  61 1b 59 7e
>|   f0 8c 92 4c
>| **parse ISAKMP Message:
>|    initiator cookie:
>|   3f 38 80 4f  d3 db a5 9f
>|    responder cookie:
>|   c2 36 4a 02  d0 15 cc 47
>|    next payload type: ISAKMP_NEXT_KE
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_IDPROT
>|    flags: none
>|    message ID:  00 00 00 00
>|    length: 244
>|  processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
>| ICOOKIE:  3f 38 80 4f  d3 db a5 9f
>| RCOOKIE:  c2 36 4a 02  d0 15 cc 47
>| state hash entry 30
>| v1 peer and cookies match on #1, provided msgid 00000000 vs 00000000
>| v1 state object #1 found, in STATE_MAIN_I2
>| processing connection v4
>| got payload 0x10(ISAKMP_NEXT_KE) needed: 0x410 opt: 0x102080
>| ***parse ISAKMP Key Exchange Payload:
>|    next payload type: ISAKMP_NEXT_NONCE
>|    length: 196
>| got payload 0x400(ISAKMP_NEXT_NONCE) needed: 0x400 opt: 0x102080
>| ***parse ISAKMP Nonce Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 20
>| **emit ISAKMP Message:
>|    initiator cookie:
>|   3f 38 80 4f  d3 db a5 9f
>|    responder cookie:
>|   c2 36 4a 02  d0 15 cc 47
>|    next payload type: ISAKMP_NEXT_ID
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_IDPROT
>|    flags: ISAKMP_FLAG_ENCRYPTION
>|    message ID:  00 00 00 00
>| DH public value received:
>|   ba a0 2e e7  cc a1 f7 df  a3 7f 7b f0  d8 ea d8 54
>|   24 11 59 7a  2b 0b a7 4b  95 ba 40 ee  9a 4d 86 98
>|   6a 87 d0 67  60 5a 88 dc  63 88 63 b9  4f be 71 32
>|   72 0a b4 b8  ea b1 a2 de  9b 16 01 85  c9 7a af 50
>|   54 9f 30 2a  6a fa b6 27  8a 08 21 7e  47 7d 33 c0
>|   5b 92 dd 83  ac a3 6e f2  c7 0c a1 8d  8c e9 4b 0a
>|   8c b7 b4 8e  74 2e 48 3f  53 6b 36 7b  ec 04 c3 84
>|   80 0a 9f 9c  db ea 10 b0  59 b4 b1 d3  99 05 67 b0
>|   4a 06 26 43  81 bc 56 f4  ef 0a 88 76  fd 05 8d 8f
>|   e9 8e ea 40  70 f0 2f db  30 40 12 33  79 69 a6 aa
>|   ff d5 da 45  3d 3c fc 64  80 52 c6 f0  fc d1 22 51
>|   ad 74 97 28  5f c4 0e 56  13 bd 19 44  df 79 54 08
>| started looking for secret for 192.1.2.23->192.1.2.45 of kind PPK_PSK
>| actually looking for secret for 192.1.2.23->192.1.2.45 of kind PPK_PSK
>| line 2: key type PPK_PSK(192.1.2.23) to type PPK_PSK 
>| 1: compared key 2001:db8:1:2::45 to 192.1.2.23 / 192.1.2.45 -> 0
>| 2: compared key 2001:db8:1:2::23 to 192.1.2.23 / 192.1.2.45 -> 0
>| line 2: match=0 
>| line 1: key type PPK_PSK(192.1.2.23) to type PPK_PSK 
>| 1: compared key 192.1.2.23 to 192.1.2.23 / 192.1.2.45 -> 8
>| 2: compared key 192.1.2.45 to 192.1.2.23 / 192.1.2.45 -> 12
>| line 1: match=12 
>| best_match 0>12 best=0x2b49aca0d130 (line=1)
>| concluding with best_match=12 best=0x2b49aca0d130 (lineno=1)
>| parent1 type: 7 group: 5 len: 2776 
>| Copying DH pub key pointer to be sent to a thread helper
>| 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
>| asking helper 0 to do compute dh+iv op on seq: 2 (len=2776, pcw_work=1)
>| helper 0 read 2768+4/2776 bytes fd: 10
>| helper 0 doing compute dh+iv op id: 2
>| peer's g:   ba a0 2e e7  cc a1 f7 df  a3 7f 7b f0  d8 ea d8 54
>| peer's g:   24 11 59 7a  2b 0b a7 4b  95 ba 40 ee  9a 4d 86 98
>| peer's g:   6a 87 d0 67  60 5a 88 dc  63 88 63 b9  4f be 71 32
>| peer's g:   72 0a b4 b8  ea b1 a2 de  9b 16 01 85  c9 7a af 50
>| peer's g:   54 9f 30 2a  6a fa b6 27  8a 08 21 7e  47 7d 33 c0
>| peer's g:   5b 92 dd 83  ac a3 6e f2  c7 0c a1 8d  8c e9 4b 0a
>| peer's g:   8c b7 b4 8e  74 2e 48 3f  53 6b 36 7b  ec 04 c3 84
>| peer's g:   80 0a 9f 9c  db ea 10 b0  59 b4 b1 d3  99 05 67 b0
>| peer's g:   4a 06 26 43  81 bc 56 f4  ef 0a 88 76  fd 05 8d 8f
>| peer's g:   e9 8e ea 40  70 f0 2f db  30 40 12 33  79 69 a6 aa
>| peer's g:   ff d5 da 45  3d 3c fc 64  80 52 c6 f0  fc d1 22 51
>| peer's g:   ad 74 97 28  5f c4 0e 56  13 bd 19 44  df 79 54 08
>| Started DH shared-secret computation in NSS: 
>| Dropped no leading zeros 192
>| calc_dh_shared(): time elapsed (OAKLEY_GROUP_MODP1536): 402 usec
>| DH shared-secret pointer:
>|   50 6f a2 ac  49 2b 00 00
>| NSS: skeyid inputs (pss+NI+NR+shared) hasher: oakley_sha
>| shared-secret:   50 6f a2 ac  49 2b 00 00
>| ni:   3f 70 89 5a  2d f4 11 32  47 a5 ed 11  cf a6 a2 92
>| nr:   20 85 80 f4  ba 94 6c 3b  61 1b 59 7e  f0 8c 92 4c
>| NSS: st_skeyid in skeyid_preshared(): 
>|   90 04 a3 ac  49 2b 00 00
>| NSS: Started key computation 
>| NSS: enc keysize=24 
>| NSS: Freed 25-39 symkeys 
>| NSS: copied skeyid_d_chunk 
>| NSS: copied skeyid_a_chunk 
>| NSS: copied skeyid_e_chunk 
>| NSS: copied enc_key_chunk 
>| NSS: Freed symkeys 1-23 
>| NSS: Freed padding chunks 
>| DH_i:  d2 15 21 87  31 47 8f 4a  b3 e3 0c 96  ca d2 68 be
>| DH_i:  f1 73 3f 27  ca fb 38 8b  ea 66 1b f0  7c b3 33 92
>| DH_i:  79 bb 9f e5  3a a5 06 21  11 42 96 42  27 d3 1c 2c
>| DH_i:  a6 ff a1 ed  3b 1f a0 b9  77 80 27 70  49 ad 28 e5
>| DH_i:  7f ae c3 aa  43 15 de 75  0f 73 ba dc  27 40 d5 5e
>| DH_i:  6b e5 09 8d  ce 55 61 12  3d e9 a8 d2  1c 4f 69 85
>| DH_i:  5d 4f ca 87  16 12 bf 3c  b8 1e eb 2e  2d ae d5 2e
>| DH_i:  8e 13 c2 04  e0 4a 99 87  10 48 8d b6  50 3a 7f 70
>| DH_i:  d8 0e f6 a4  2a b1 15 af  43 59 1e 7f  c5 fe 4b f2
>| DH_i:  45 97 48 c3  cb 8c f5 41  b8 cd 16 cd  85 44 8e 60
>| DH_i:  2a 88 f6 7b  b5 23 1d b8  ea 83 c9 3a  c7 3a 1d 21
>| DH_i:  e9 57 3c a2  58 8a 48 88  00 d8 54 5a  be 0f b4 c7
>| DH_r:  ba a0 2e e7  cc a1 f7 df  a3 7f 7b f0  d8 ea d8 54
>| DH_r:  24 11 59 7a  2b 0b a7 4b  95 ba 40 ee  9a 4d 86 98
>| DH_r:  6a 87 d0 67  60 5a 88 dc  63 88 63 b9  4f be 71 32
>| DH_r:  72 0a b4 b8  ea b1 a2 de  9b 16 01 85  c9 7a af 50
>| DH_r:  54 9f 30 2a  6a fa b6 27  8a 08 21 7e  47 7d 33 c0
>| DH_r:  5b 92 dd 83  ac a3 6e f2  c7 0c a1 8d  8c e9 4b 0a
>| DH_r:  8c b7 b4 8e  74 2e 48 3f  53 6b 36 7b  ec 04 c3 84
>| DH_r:  80 0a 9f 9c  db ea 10 b0  59 b4 b1 d3  99 05 67 b0
>| DH_r:  4a 06 26 43  81 bc 56 f4  ef 0a 88 76  fd 05 8d 8f
>| DH_r:  e9 8e ea 40  70 f0 2f db  30 40 12 33  79 69 a6 aa
>| DH_r:  ff d5 da 45  3d 3c fc 64  80 52 c6 f0  fc d1 22 51
>| DH_r:  ad 74 97 28  5f c4 0e 56  13 bd 19 44  df 79 54 08
>| end of IV generation 
>| crypto helper write of request: cnt=2776<wlen=2776.  
>| deleting event for #1
>| inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #1
>| event added after event EVENT_PENDING_PHASE2
>| complete state transition with STF_SUSPEND
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 10 seconds for #2
>| next event EVENT_RETRANSMIT in 10 seconds for #2
>| 
>| helper 0 has finished work (cnt now 1)
>| helper 0 replies to id: q#2
>| calling callback function 0x2b49ac6d9ab0
>| main inR2_outI3: calculated DH, sending R1
>| processing connection v4
>| thinking about whether to send my certificate:
>|   I have RSA key: OAKLEY_PRESHARED_KEY cert.type: CERT_NONE 
>|   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)
>|  I am not sending a certificate request
>| ***emit ISAKMP Identification Payload (IPsec DOI):
>|    next payload type: ISAKMP_NEXT_HASH
>|    ID type: ID_IPV4_ADDR
>|    Protocol ID: 0
>|    port: 0
>| emitting 4 raw bytes of my identity into ISAKMP Identification Payload (IPsec DOI)
>| my identity  c0 01 02 17
>| emitting length of ISAKMP Identification Payload (IPsec DOI): 12
>| hashing 80 bytes of SA
>| ***emit ISAKMP Hash Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>| emitting 20 raw bytes of HASH_I into ISAKMP Hash Payload
>| HASH_I  da 6c a1 8a  cb c9 80 43  2a 38 ea a8  e8 48 93 af
>| HASH_I  c8 c2 96 f0
>| emitting length of ISAKMP Hash Payload: 24
>| encrypting:
>|   08 00 00 0c  01 00 00 00  c0 01 02 17  00 00 00 18
>|   da 6c a1 8a  cb c9 80 43  2a 38 ea a8  e8 48 93 af
>|   c8 c2 96 f0
>| IV:
>|   63 5a 7e bd  48 b4 6e 1b  2a 58 0f 2e  a8 61 85 4a
>|   4d c1 73 c1
>| unpadded size is: 36
>| emitting 4 zero bytes of encryption padding into ISAKMP Message
>| encrypting 40 using OAKLEY_3DES_CBC
>| NSS: do_3des init start
>| NSS: do_3des init end
>| next IV:  21 42 f7 d1  8e 48 68 f9
>| emitting length of ISAKMP Message: 68
>| complete state transition with STF_OK
>"v4" #1: transition from state STATE_MAIN_I2 to state STATE_MAIN_I3
>| deleting event for #1
>| sending reply packet to 192.1.2.45:500 (from port 500)
>| sending 68 bytes for STATE_MAIN_I2 through eth1:500 to 192.1.2.45:500 (using #1)
>|   3f 38 80 4f  d3 db a5 9f  c2 36 4a 02  d0 15 cc 47
>|   05 10 02 01  00 00 00 00  00 00 00 44  35 2b af 81
>|   0f 8e 37 62  dc f8 2c 20  5d a2 62 91  38 11 1f a1
>|   63 26 d7 01  b0 25 46 30  39 27 1a fc  21 42 f7 d1
>|   8e 48 68 f9
>| inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
>| event added at head of queue
>"v4" #1: STATE_MAIN_I3: sent MI3, expecting MR3
>| modecfg pull: noquirk policy:push not-client
>| phase 1 is done, looking for phase 2 to unpend
>| * processed 1 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 10 seconds for #1
>| next event EVENT_RETRANSMIT in 10 seconds for #1
>| 
>| *received 76 bytes from 192.1.2.45:500 on eth1 (port=500)
>|   3f 38 80 4f  d3 db a5 9f  c2 36 4a 02  d0 15 cc 47
>|   05 10 02 01  00 00 00 00  00 00 00 4c  37 49 3c b8
>|   9f 8f 91 1d  cf 57 94 fe  1a 4c 77 d3  b5 e8 68 40
>|   09 fe 16 e8  c4 d0 0d 41  01 11 b6 ca  8a ae a0 97
>|   bb 5f 15 c4  4e d8 3a 72  85 b5 68 aa
>| **parse ISAKMP Message:
>|    initiator cookie:
>|   3f 38 80 4f  d3 db a5 9f
>|    responder cookie:
>|   c2 36 4a 02  d0 15 cc 47
>|    next payload type: ISAKMP_NEXT_ID
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_IDPROT
>|    flags: ISAKMP_FLAG_ENCRYPTION
>|    message ID:  00 00 00 00
>|    length: 76
>|  processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
>| ICOOKIE:  3f 38 80 4f  d3 db a5 9f
>| RCOOKIE:  c2 36 4a 02  d0 15 cc 47
>| state hash entry 30
>| v1 peer and cookies match on #1, provided msgid 00000000 vs 00000000
>| v1 state object #1 found, in STATE_MAIN_I3
>| processing connection v4
>| received encrypted packet from 192.1.2.45:500
>| decrypting 48 bytes using algorithm OAKLEY_3DES_CBC
>| NSS: do_3des init start
>| NSS: do_3des init end
>| decrypted:
>|   08 00 00 0c  01 00 00 00  c0 01 02 2d  0d 00 00 18
>|   98 97 89 34  4e 2e 5b 2a  1d 3e 87 34  77 38 b9 61
>|   d1 4b 8d 24  00 00 00 09  49 4b 45 76  32 00 00 00
>| next IV:  4e d8 3a 72  85 b5 68 aa
>| got payload 0x20(ISAKMP_NEXT_ID) needed: 0x120 opt: 0x2080
>| ***parse ISAKMP Identification Payload:
>|    next payload type: ISAKMP_NEXT_HASH
>|    length: 12
>|    ID type: ID_IPV4_ADDR
>|    DOI specific A: 0
>|    DOI specific B: 0
>|      obj:   c0 01 02 2d
>| got payload 0x100(ISAKMP_NEXT_HASH) needed: 0x100 opt: 0x2080
>| ***parse ISAKMP Hash Payload:
>|    next payload type: ISAKMP_NEXT_VID
>|    length: 24
>| got payload 0x2000(ISAKMP_NEXT_VID) needed: 0x0 opt: 0x2080
>| ***parse ISAKMP Vendor ID Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 9
>| removing 3 bytes of padding
>"v4" #1: received Vendor ID payload [CAN-IKEv2]
>"v4" #1: Main mode peer ID is ID_IPV4_ADDR: '192.1.2.45'
>| hashing 80 bytes of SA
>| authentication succeeded
>| complete state transition with STF_OK
>"v4" #1: transition from state STATE_MAIN_I3 to state STATE_MAIN_I4
>| deleting event for #1
>| inserting event EVENT_SA_REPLACE, timeout in 2607 seconds for #1
>| event added after event EVENT_PENDING_PHASE2
>"v4" #1: STATE_MAIN_I4: ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=oakley_3des_cbc_192 prf=oakley_sha group=modp1536}
>| modecfg pull: noquirk policy:push not-client
>| phase 1 is done, looking for phase 2 to unpend
>| unpending state #1
>| unqueuing pending Quick Mode with 192.1.2.45 "v4" import:admin initiate
>| duplicating state object #1
>| creating state object #3 at 0x2b49aca2a400
>| processing connection v4
>| ICOOKIE:  3f 38 80 4f  d3 db a5 9f
>| RCOOKIE:  c2 36 4a 02  d0 15 cc 47
>| state hash entry 30
>| inserting state object #3 on chain 30
>| inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #3
>| event added at head of queue
>| kernel_alg_esp_enc_ok(3,0): alg_id=3, alg_ivlen=8, alg_minbits=192, alg_maxbits=192, res=0, ret=1
>| kernel_alg_esp_enc_keylen():alg_id=3, keylen=24
>| kernel_alg_esp_auth_keylen(auth=2, sadb_aalg=3): a_keylen=20
>"v4" #3: initiating Quick Mode PSK+ENCRYPT+UP+IKEv2ALLOW+SAREFTRACK {using isakmp#1 msgid:1176b035 proposal=3DES(3)_192-SHA1(2)_160 pfsgroup=no-pfs}
>| 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
>| asking helper 0 to do build_nonce op on seq: 3 (len=2776, pcw_work=1)
>| helper 0 read 2768+4/2776 bytes fd: 10
>| helper 0 doing build_nonce op id: 3
>| Generated nonce:
>|   d1 d1 f4 5c  06 d6 b1 f0  aa ad 18 a9  c0 3b 51 b7
>| crypto helper write of request: cnt=2776<wlen=2776.  
>| deleting event for #3
>| inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #3
>| event added after event EVENT_PENDING_PHASE2
>| removing pending policy for "none" {0x2b49aca0d9b0}
>| unqueuing pending Quick Mode with 192.1.2.45 "v4" import:admin initiate
>| duplicating state object #1
>| creating state object #4 at 0x2b49aca2aba0
>| processing connection v4
>| ICOOKIE:  3f 38 80 4f  d3 db a5 9f
>| RCOOKIE:  c2 36 4a 02  d0 15 cc 47
>| state hash entry 30
>| inserting state object #4 on chain 30
>| inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #4
>| event added at head of queue
>| kernel_alg_esp_enc_ok(3,0): alg_id=3, alg_ivlen=8, alg_minbits=192, alg_maxbits=192, res=0, ret=1
>| kernel_alg_esp_enc_keylen():alg_id=3, keylen=24
>| kernel_alg_esp_auth_keylen(auth=2, sadb_aalg=3): a_keylen=20
>"v4" #4: initiating Quick Mode PSK+ENCRYPT+IKEv2ALLOW+SAREFTRACK {using isakmp#1 msgid:ee4c1bed proposal=3DES(3)_192-SHA1(2)_160 pfsgroup=no-pfs}
>| 0: w->pcw_dead: 0 w->pcw_work: 1 cnt: 1
>| asking helper 0 to do build_nonce op on seq: 4 (len=2776, pcw_work=2)
>| helper 0 read 2768+4/2776 bytes fd: 10
>| helper 0 doing build_nonce op id: 4
>| Generated nonce:
>|   9b 0d af 3f  4d ea 94 88  63 ff 7f 54  34 c1 d9 dc
>| crypto helper write of request: cnt=2776<wlen=2776.  
>| deleting event for #4
>| inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #4
>| event added after event EVENT_PENDING_PHASE2
>| removing pending policy for "none" {0x2b49aca0da80}
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 10 seconds for #2
>| next event EVENT_RETRANSMIT in 10 seconds for #2
>| 
>| helper 0 has finished work (cnt now 2)
>| helper 0 replies to id: q#3
>| calling callback function 0x2b49ac6e0710
>| quick outI1: calculated ke+nonce, sending I1
>| processing connection v4
>| **emit ISAKMP Message:
>|    initiator cookie:
>|   3f 38 80 4f  d3 db a5 9f
>|    responder cookie:
>|   c2 36 4a 02  d0 15 cc 47
>|    next payload type: ISAKMP_NEXT_HASH
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_QUICK
>|    flags: ISAKMP_FLAG_ENCRYPTION
>|    message ID:  35 b0 76 11
>| ***emit ISAKMP Hash Payload:
>|    next payload type: ISAKMP_NEXT_SA
>| emitting 20 zero bytes of HASH into ISAKMP Hash Payload
>| emitting length of ISAKMP Hash Payload: 24
>| kernel_alg_db_new() initial trans_cnt=90
>| 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
>| ***emit ISAKMP Security Association Payload:
>|    next payload type: ISAKMP_NEXT_NONCE
>|    DOI: ISAKMP_DOI_IPSEC
>| ****emit IPsec DOI SIT:
>|    IPsec DOI SIT: SIT_IDENTITY_ONLY
>| out_sa pcn: 0 has 1 valid proposals
>| out_sa pcn: 0 pn: 0<1 valid_count: 1 trans_cnt: 1
>| ****emit ISAKMP Proposal Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    proposal number: 0
>|    protocol ID: PROTO_IPSEC_ESP
>|    SPI size: 4
>|    number of transforms: 1
>| netlink_get_spi: allocated 0x8a85863c for esp.0@192.1.2.23
>| emitting 4 raw bytes of SPI into ISAKMP Proposal Payload
>| SPI  8a 85 86 3c
>| *****emit ISAKMP Transform Payload (ESP):
>|    next payload type: ISAKMP_NEXT_NONE
>|    transform number: 0
>|    transform ID: ESP_3DES
>| ******emit ISAKMP IPsec DOI attribute:
>|    af+type: ENCAPSULATION_MODE
>|    length/value: 2
>|     [2 is ENCAPSULATION_MODE_TRANSPORT]
>| ******emit ISAKMP IPsec DOI attribute:
>|    af+type: SA_LIFE_TYPE
>|    length/value: 1
>|     [1 is SA_LIFE_TYPE_SECONDS]
>| ******emit ISAKMP IPsec DOI attribute:
>|    af+type: SA_LIFE_DURATION
>|    length/value: 28800
>| ******emit ISAKMP IPsec DOI attribute:
>|    af+type: AUTH_ALGORITHM
>|    length/value: 2
>|     [2 is AUTH_ALGORITHM_HMAC_SHA1]
>| emitting length of ISAKMP Transform Payload (ESP): 24
>| emitting length of ISAKMP Proposal Payload: 36
>| emitting length of ISAKMP Security Association Payload: 48
>| ***emit ISAKMP Nonce Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>| emitting 16 raw bytes of Ni into ISAKMP Nonce Payload
>| Ni  d1 d1 f4 5c  06 d6 b1 f0  aa ad 18 a9  c0 3b 51 b7
>| emitting length of ISAKMP Nonce Payload: 20
>| HASH(1) computed:
>|   d8 03 65 78  ac b8 b0 16  9a b2 6a 25  28 05 4f 89
>|   02 52 99 2e
>| last Phase 1 IV:  4e d8 3a 72  85 b5 68 aa
>| current Phase 1 IV:  4e d8 3a 72  85 b5 68 aa
>| computed Phase 2 IV:
>|   f3 46 a4 0e  8a 8a 19 9a  ff 02 c9 9d  6e 56 2a af
>|   d8 96 c3 a4
>| encrypting:
>|   01 00 00 18  d8 03 65 78  ac b8 b0 16  9a b2 6a 25
>|   28 05 4f 89  02 52 99 2e  0a 00 00 30  00 00 00 01
>|   00 00 00 01  00 00 00 24  00 03 04 01  8a 85 86 3c
>|   00 00 00 18  00 03 00 00  80 04 00 02  80 01 00 01
>|   80 02 70 80  80 05 00 02  00 00 00 14  d1 d1 f4 5c
>|   06 d6 b1 f0  aa ad 18 a9  c0 3b 51 b7
>| IV:
>|   f3 46 a4 0e  8a 8a 19 9a  ff 02 c9 9d  6e 56 2a af
>|   d8 96 c3 a4
>| unpadded size is: 92
>| emitting 4 zero bytes of encryption padding into ISAKMP Message
>| encrypting 96 using OAKLEY_3DES_CBC
>| NSS: do_3des init start
>| NSS: do_3des init end
>| next IV:  a2 d0 d5 cd  fe d8 90 27
>| emitting length of ISAKMP Message: 124
>| sending 124 bytes for quick_outI1 through eth1:500 to 192.1.2.45:500 (using #3)
>|   3f 38 80 4f  d3 db a5 9f  c2 36 4a 02  d0 15 cc 47
>|   08 10 20 01  35 b0 76 11  00 00 00 7c  79 00 16 8d
>|   fd 34 ef 1d  a5 dd 7a af  d2 43 55 85  0c d7 9a 19
>|   85 22 9a 9e  e4 8f df b8  b4 fa 34 b8  79 62 e8 17
>|   5b 59 0b 3d  85 52 6f 4b  c5 e0 6b d8  76 b1 67 6c
>|   76 49 59 8d  45 ac 2b 21  b4 1e c2 49  35 ef dc af
>|   30 b5 ee 92  96 1d 58 83  83 f5 58 38  a8 83 a3 08
>|   bc 68 31 ae  a2 d0 d5 cd  fe d8 90 27
>| deleting event for #3
>| inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #3
>| event added at head of queue
>| * processed 1 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 10 seconds for #3
>| next event EVENT_RETRANSMIT in 10 seconds for #3
>| 
>| helper 0 has finished work (cnt now 1)
>| helper 0 replies to id: q#4
>| calling callback function 0x2b49ac6e0710
>| quick outI1: calculated ke+nonce, sending I1
>| processing connection v4
>| **emit ISAKMP Message:
>|    initiator cookie:
>|   3f 38 80 4f  d3 db a5 9f
>|    responder cookie:
>|   c2 36 4a 02  d0 15 cc 47
>|    next payload type: ISAKMP_NEXT_HASH
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_QUICK
>|    flags: ISAKMP_FLAG_ENCRYPTION
>|    message ID:  ed 1b 4c ee
>| ***emit ISAKMP Hash Payload:
>|    next payload type: ISAKMP_NEXT_SA
>| emitting 20 zero bytes of HASH into ISAKMP Hash Payload
>| emitting length of ISAKMP Hash Payload: 24
>| kernel_alg_db_new() initial trans_cnt=90
>| 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
>| ***emit ISAKMP Security Association Payload:
>|    next payload type: ISAKMP_NEXT_NONCE
>|    DOI: ISAKMP_DOI_IPSEC
>| ****emit IPsec DOI SIT:
>|    IPsec DOI SIT: SIT_IDENTITY_ONLY
>| out_sa pcn: 0 has 1 valid proposals
>| out_sa pcn: 0 pn: 0<1 valid_count: 1 trans_cnt: 1
>| ****emit ISAKMP Proposal Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    proposal number: 0
>|    protocol ID: PROTO_IPSEC_ESP
>|    SPI size: 4
>|    number of transforms: 1
>| netlink_get_spi: allocated 0xe116bd19 for esp.0@192.1.2.23
>| emitting 4 raw bytes of SPI into ISAKMP Proposal Payload
>| SPI  e1 16 bd 19
>| *****emit ISAKMP Transform Payload (ESP):
>|    next payload type: ISAKMP_NEXT_NONE
>|    transform number: 0
>|    transform ID: ESP_3DES
>| ******emit ISAKMP IPsec DOI attribute:
>|    af+type: ENCAPSULATION_MODE
>|    length/value: 2
>|     [2 is ENCAPSULATION_MODE_TRANSPORT]
>| ******emit ISAKMP IPsec DOI attribute:
>|    af+type: SA_LIFE_TYPE
>|    length/value: 1
>|     [1 is SA_LIFE_TYPE_SECONDS]
>| ******emit ISAKMP IPsec DOI attribute:
>|    af+type: SA_LIFE_DURATION
>|    length/value: 28800
>| ******emit ISAKMP IPsec DOI attribute:
>|    af+type: AUTH_ALGORITHM
>|    length/value: 2
>|     [2 is AUTH_ALGORITHM_HMAC_SHA1]
>| emitting length of ISAKMP Transform Payload (ESP): 24
>| emitting length of ISAKMP Proposal Payload: 36
>| emitting length of ISAKMP Security Association Payload: 48
>| ***emit ISAKMP Nonce Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>| emitting 16 raw bytes of Ni into ISAKMP Nonce Payload
>| Ni  9b 0d af 3f  4d ea 94 88  63 ff 7f 54  34 c1 d9 dc
>| emitting length of ISAKMP Nonce Payload: 20
>| HASH(1) computed:
>|   23 30 53 d2  28 93 15 df  f6 f3 66 c3  26 0e e2 94
>|   d6 66 64 ed
>| last Phase 1 IV:  4e d8 3a 72  85 b5 68 aa
>| current Phase 1 IV:  4e d8 3a 72  85 b5 68 aa
>| computed Phase 2 IV:
>|   d9 ad 92 59  55 4b 61 f9  6d 35 57 64  c8 6a b3 02
>|   11 cd 32 26
>| encrypting:
>|   01 00 00 18  23 30 53 d2  28 93 15 df  f6 f3 66 c3
>|   26 0e e2 94  d6 66 64 ed  0a 00 00 30  00 00 00 01
>|   00 00 00 01  00 00 00 24  00 03 04 01  e1 16 bd 19
>|   00 00 00 18  00 03 00 00  80 04 00 02  80 01 00 01
>|   80 02 70 80  80 05 00 02  00 00 00 14  9b 0d af 3f
>|   4d ea 94 88  63 ff 7f 54  34 c1 d9 dc
>| IV:
>|   d9 ad 92 59  55 4b 61 f9  6d 35 57 64  c8 6a b3 02
>|   11 cd 32 26
>| unpadded size is: 92
>| emitting 4 zero bytes of encryption padding into ISAKMP Message
>| encrypting 96 using OAKLEY_3DES_CBC
>| NSS: do_3des init start
>| NSS: do_3des init end
>| next IV:  18 49 b4 ac  4b d8 9f 5f
>| emitting length of ISAKMP Message: 124
>| sending 124 bytes for quick_outI1 through eth1:500 to 192.1.2.45:500 (using #4)
>|   3f 38 80 4f  d3 db a5 9f  c2 36 4a 02  d0 15 cc 47
>|   08 10 20 01  ed 1b 4c ee  00 00 00 7c  3e dc 9c 41
>|   38 90 b8 4e  5e ff a2 32  c4 4e 18 25  e0 01 52 ea
>|   d7 3f 9a 58  d5 64 a3 0a  bd 82 c8 c0  e9 29 f9 0a
>|   82 45 c0 8c  26 13 fd 9d  b2 6a 96 b5  52 de 33 ce
>|   54 c2 a5 ca  5e 9e 27 d8  06 5c 37 9a  8b 53 d8 81
>|   82 53 c6 72  0c 81 21 26  f1 ab 22 12  ca a1 d8 bf
>|   08 d8 09 19  18 49 b4 ac  4b d8 9f 5f
>| deleting event for #4
>| inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #4
>| event added at head of queue
>| * processed 1 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 10 seconds for #4
>| next event EVENT_RETRANSMIT in 10 seconds for #4
>| 
>| *received 124 bytes from 192.1.2.45:500 on eth1 (port=500)
>|   3f 38 80 4f  d3 db a5 9f  c2 36 4a 02  d0 15 cc 47
>|   08 10 20 01  35 b0 76 11  00 00 00 7c  88 72 a8 81
>|   ea c5 1a 41  37 b5 66 bc  47 37 e1 80  31 ae c7 0b
>|   1f 6c 80 65  77 56 0f 30  3c 5a e4 2d  a0 58 25 a8
>|   73 c7 76 c1  23 e9 4a e9  c3 f4 2b 7a  b9 27 7d ca
>|   cb 3e cc 0d  4a b8 96 02  0a 60 ca 2f  a3 4f 9c f1
>|   dd 2b cf 08  2c 56 91 9d  df 40 b2 73  d3 59 c9 c5
>|   e3 71 51 2f  77 c6 4d 16  92 df 0e 97
>| **parse ISAKMP Message:
>|    initiator cookie:
>|   3f 38 80 4f  d3 db a5 9f
>|    responder cookie:
>|   c2 36 4a 02  d0 15 cc 47
>|    next payload type: ISAKMP_NEXT_HASH
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_QUICK
>|    flags: ISAKMP_FLAG_ENCRYPTION
>|    message ID:  35 b0 76 11
>|    length: 124
>|  processing version=1.0 packet with exchange type=ISAKMP_XCHG_QUICK (32)
>| ICOOKIE:  3f 38 80 4f  d3 db a5 9f
>| RCOOKIE:  c2 36 4a 02  d0 15 cc 47
>| state hash entry 30
>| v1 peer and cookies match on #4, provided msgid 35b07611 vs ed1b4cee
>| v1 peer and cookies match on #3, provided msgid 35b07611 vs 35b07611
>| v1 state object #3 found, in STATE_QUICK_I1
>| processing connection v4
>| received encrypted packet from 192.1.2.45:500
>| decrypting 96 bytes using algorithm OAKLEY_3DES_CBC
>| NSS: do_3des init start
>| NSS: do_3des init end
>| decrypted:
>|   01 00 00 18  98 52 72 fe  da 5e af d6  fd e0 92 7d
>|   1e 46 48 7f  fc 80 d0 e6  0a 00 00 30  00 00 00 01
>|   00 00 00 01  00 00 00 24  00 03 04 01  27 09 6f 94
>|   00 00 00 18  00 03 00 00  80 04 00 02  80 01 00 01
>|   80 02 70 80  80 05 00 02  00 00 00 14  05 23 7b 7e
>|   76 90 7e 21  71 32 54 f7  7f 78 83 d1  00 00 00 00
>| next IV:  77 c6 4d 16  92 df 0e 97
>| got payload 0x100(ISAKMP_NEXT_HASH) needed: 0x502 opt: 0x200030
>| ***parse ISAKMP Hash Payload:
>|    next payload type: ISAKMP_NEXT_SA
>|    length: 24
>| got payload 0x2(ISAKMP_NEXT_SA) needed: 0x402 opt: 0x200030
>| ***parse ISAKMP Security Association Payload:
>|    next payload type: ISAKMP_NEXT_NONCE
>|    length: 48
>|    DOI: ISAKMP_DOI_IPSEC
>| got payload 0x400(ISAKMP_NEXT_NONCE) needed: 0x400 opt: 0x200030
>| ***parse ISAKMP Nonce Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 20
>| removing 4 bytes of padding
>| **emit ISAKMP Message:
>|    initiator cookie:
>|   3f 38 80 4f  d3 db a5 9f
>|    responder cookie:
>|   c2 36 4a 02  d0 15 cc 47
>|    next payload type: ISAKMP_NEXT_HASH
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_QUICK
>|    flags: ISAKMP_FLAG_ENCRYPTION
>|    message ID:  35 b0 76 11
>| HASH(2) computed:
>|   98 52 72 fe  da 5e af d6  fd e0 92 7d  1e 46 48 7f
>|   fc 80 d0 e6
>| ****parse IPsec DOI SIT:
>|    IPsec DOI SIT: SIT_IDENTITY_ONLY
>| ****parse ISAKMP Proposal Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 36
>|    proposal number: 0
>|    protocol ID: PROTO_IPSEC_ESP
>|    SPI size: 4
>|    number of transforms: 1
>| parsing 4 raw bytes of ISAKMP Proposal Payload into SPI
>| SPI  27 09 6f 94
>| *****parse ISAKMP Transform Payload (ESP):
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 24
>|    transform number: 0
>|    transform ID: ESP_3DES
>| ******parse ISAKMP IPsec DOI attribute:
>|    af+type: ENCAPSULATION_MODE
>|    length/value: 2
>|    [2 is ENCAPSULATION_MODE_TRANSPORT]
>| ******parse ISAKMP IPsec DOI attribute:
>|    af+type: SA_LIFE_TYPE
>|    length/value: 1
>| ******parse ISAKMP IPsec DOI attribute:
>|    af+type: SA_LIFE_DURATION
>|    length/value: 28800
>| ******parse ISAKMP IPsec DOI attribute:
>|    af+type: AUTH_ALGORITHM
>|    length/value: 2
>| kernel_alg_esp_enc_ok(3,0): alg_id=3, alg_ivlen=8, alg_minbits=192, alg_maxbits=192, res=0, ret=1
>| kernel_alg_esp_enc_keylen():alg_id=3, keylen=24
>| ***emit ISAKMP Hash Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>| emitting 20 zero bytes of HASH into ISAKMP Hash Payload
>| emitting length of ISAKMP Hash Payload: 24
>| HASH(3) computed:  44 ce a0 d0  ea 58 6a 8a  0d 00 05 ec  3a e8 80 c0
>| HASH(3) computed:  6c 4b 2d ce
>| compute_proto_keymat:needed_len (after ESP enc)=24
>| compute_proto_keymat:needed_len (after ESP auth)=44
>| ESP KEYMAT 
>|   KEYMAT computed:
>|   f5 81 c2 0d  b0 83 94 22  6a 50 c9 96  c6 21 0c 7a
>|   d9 88 ff 87  40 68 6f a0  4c 05 5b 87  90 e8 80 f4
>|   65 fc 1d c0  2d d4 f3 9b  f8 46 a7 5e
>|   Peer KEYMAT computed:
>|   94 c7 73 82  13 ea 51 02  43 60 ac b3  c8 0b d6 be
>|   45 8d ae 53  be 5e ff 8a  07 bf d7 72  4f da ac 94
>|   56 19 21 24  69 25 a1 49  8d 5c d9 04
>| install_ipsec_sa() for #3: inbound and outbound
>| route owner of "v4" erouted HOLD: self; eroute owner: self
>| could_route called for v4 (kind=CK_PERMANENT)
>| looking for alg with transid: 3 keylen: 0 auth: 2 
>| checking transid: 11 keylen: 0 auth: 1 
>| checking transid: 11 keylen: 0 auth: 2 
>| checking transid: 2 keylen: 8 auth: 0 
>| checking transid: 2 keylen: 8 auth: 1 
>| checking transid: 2 keylen: 8 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:  94 c7 73 82  13 ea 51 02  43 60 ac b3  c8 0b d6 be
>| esp enckey:  45 8d ae 53  be 5e ff 8a
>| esp authkey:  07 bf d7 72  4f da ac 94  56 19 21 24  69 25 a1 49
>| esp authkey:  8d 5c d9 04
>|   using old struct xfrm_algo for XFRM message
>| set up outoing SA, ref=0/4294901761
>| looking for alg with transid: 3 keylen: 0 auth: 2 
>| checking transid: 11 keylen: 0 auth: 1 
>| checking transid: 11 keylen: 0 auth: 2 
>| checking transid: 2 keylen: 8 auth: 0 
>| checking transid: 2 keylen: 8 auth: 1 
>| checking transid: 2 keylen: 8 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:  f5 81 c2 0d  b0 83 94 22  6a 50 c9 96  c6 21 0c 7a
>| esp enckey:  d9 88 ff 87  40 68 6f a0
>| esp authkey:  4c 05 5b 87  90 e8 80 f4  65 fc 1d c0  2d d4 f3 9b
>| esp authkey:  f8 46 a7 5e
>|   using old struct xfrm_algo for XFRM message
>| add inbound eroute 192.1.2.45/32:0 --0-> 192.1.2.23/32:0 => tun.10000@192.1.2.23 (raw_eroute)
>| raw_eroute result=1 
>| set up incoming SA, ref=0/4294901761
>| sr for #3: erouted HOLD
>| route owner of "v4" erouted HOLD: self; eroute owner: self
>| route_and_eroute with c: v4 (next: none) ero:v4 esr:{(nil)} ro:v4 rosr:{(nil)} and state: 3
>| eroute_connection replace eroute 192.1.2.23/32:0 --0-> 192.1.2.45/32:0 => esp.27096f94@192.1.2.45 (raw_eroute)
>| raw_eroute result=1 
>| command executing up-host
>| executing up-host: 2>&1 PLUTO_VERB='up-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='v4' PLUTO_INTERFACE='eth1' PLUTO_NEXT_HOP='192.1.2.45' PLUTO_ME='192.1.2.23' PLUTO_MY_ID='192.1.2.23' PLUTO_MY_CLIENT='192.1.2.23/32' PLUTO_MY_CLIENT_NET='192.1.2.23' PLUTO_MY_CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='192.1.2.45' PLUTO_PEER_ID='192.1.2.45' PLUTO_PEER_CLIENT='192.1.2.45/32' PLUTO_PEER_CLIENT_NET='192.1.2.45' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey'  PLUTO_CONN_POLICY='PSK+ENCRYPT+UP+IKEv2ALLOW+SAREFTRACK' PLUTO_XAUTH_USERNAME=''  PLUTO_IS_PEER_CISCO='0' PLUTO_CISCO_DNS_INFO='' PLUTO_CISCO_DOMAIN_INFO='' PLUTO_PEER_BANNER='' ipsec _updown
>| popen(): cmd is 745 chars long
>| cmd(   0):2>&1 PLUTO_VERB='up-host' PLUTO_VERSION='2.0' PLUTO_CONNECTION='v4' PLUTO_INTERF:
>| cmd(  80):ACE='eth1' PLUTO_NEXT_HOP='192.1.2.45' PLUTO_ME='192.1.2.23' PLUTO_MY_ID='192.1.:
>| cmd( 160):2.23' PLUTO_MY_CLIENT='192.1.2.23/32' PLUTO_MY_CLIENT_NET='192.1.2.23' PLUTO_MY_:
>| cmd( 240):CLIENT_MASK='255.255.255.255' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER:
>| cmd( 320):='192.1.2.45' PLUTO_PEER_ID='192.1.2.45' PLUTO_PEER_CLIENT='192.1.2.45/32' PLUTO:
>| cmd( 400):_PEER_CLIENT_NET='192.1.2.45' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEE:
>| cmd( 480):R_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey'  PLUTO_:
>| cmd( 560):CONN_POLICY='PSK+ENCRYPT+UP+IKEv2ALLOW+SAREFTRACK' PLUTO_XAUTH_USERNAME=''  PLUT:
>| cmd( 640):O_IS_PEER_CISCO='0' PLUTO_CISCO_DNS_INFO='' PLUTO_CISCO_DOMAIN_INFO='' PLUTO_PEE:
>| cmd( 720):R_BANNER='' ipsec _updown:
>| route_and_eroute: firewall_notified: true
>| route_and_eroute: instance "v4", setting eroute_owner {spd=0x2b49aca0a520,sr=0x2b49aca0a520} to #3 (was #0) (newest_ipsec_sa=#0)
>| encrypting:
>|   00 00 00 18  44 ce a0 d0  ea 58 6a 8a  0d 00 05 ec
>|   3a e8 80 c0  6c 4b 2d ce
>| IV:
>|   77 c6 4d 16  92 df 0e 97
>| unpadded size is: 24
>| encrypting 24 using OAKLEY_3DES_CBC
>| NSS: do_3des init start
>| NSS: do_3des init end
>| next IV:  30 6d 6f b8  1b 71 12 6f
>| emitting length of ISAKMP Message: 52
>| inR1_outI2: instance v4[0], setting newest_ipsec_sa to #3 (was #0) (spd.eroute=#3)
>| complete state transition with STF_OK
>"v4" #3: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2
>| deleting event for #3
>| sending reply packet to 192.1.2.45:500 (from port 500)
>| sending 52 bytes for STATE_QUICK_I1 through eth1:500 to 192.1.2.45:500 (using #3)
>|   3f 38 80 4f  d3 db a5 9f  c2 36 4a 02  d0 15 cc 47
>|   08 10 20 01  35 b0 76 11  00 00 00 34  d7 35 bb b6
>|   b4 ce 45 8b  f7 25 64 25  9a d7 41 a3  30 6d 6f b8
>|   1b 71 12 6f
>| inserting event EVENT_SA_REPLACE, timeout in 28048 seconds for #3
>| event added after event EVENT_LOG_DAILY
>"v4" #3: STATE_QUICK_I2: sent QI2, IPsec SA established transport mode {ESP=>0x27096f94 <0x8a85863c xfrm=3DES_0-HMAC_SHA1 NATOA=none NATD=none DPD=none}
>| modecfg pull: noquirk policy:push not-client
>| phase 1 is done, looking for phase 2 to unpend
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 10 seconds for #4
>| next event EVENT_RETRANSMIT in 10 seconds for #4
>| 
>| *received 124 bytes from 192.1.2.45:500 on eth1 (port=500)
>|   3f 38 80 4f  d3 db a5 9f  c2 36 4a 02  d0 15 cc 47
>|   08 10 20 01  ed 1b 4c ee  00 00 00 7c  04 fd 41 cc
>|   d9 0b 38 c8  d5 48 a2 f7  a9 72 38 7a  00 e5 73 6e
>|   32 06 b3 c7  59 78 1c c0  39 57 d5 df  2e c3 65 b6
>|   ac 91 2d 3a  1d 88 a8 d0  0d 3f e4 7d  ae 3d d0 7e
>|   24 12 8f dd  2c b8 bc 7a  da 72 08 73  5f 21 d7 bc
>|   3e 3b 59 91  1d f6 05 17  7d 31 9c ae  f2 26 31 0c
>|   b4 1e 73 b7  b1 65 97 eb  c7 c5 b9 82
>| **parse ISAKMP Message:
>|    initiator cookie:
>|   3f 38 80 4f  d3 db a5 9f
>|    responder cookie:
>|   c2 36 4a 02  d0 15 cc 47
>|    next payload type: ISAKMP_NEXT_HASH
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_QUICK
>|    flags: ISAKMP_FLAG_ENCRYPTION
>|    message ID:  ed 1b 4c ee
>|    length: 124
>|  processing version=1.0 packet with exchange type=ISAKMP_XCHG_QUICK (32)
>| ICOOKIE:  3f 38 80 4f  d3 db a5 9f
>| RCOOKIE:  c2 36 4a 02  d0 15 cc 47
>| state hash entry 30
>| v1 peer and cookies match on #4, provided msgid ed1b4cee vs ed1b4cee
>| v1 state object #4 found, in STATE_QUICK_I1
>| processing connection v4
>| received encrypted packet from 192.1.2.45:500
>| decrypting 96 bytes using algorithm OAKLEY_3DES_CBC
>| NSS: do_3des init start
>| NSS: do_3des init end
>| decrypted:
>|   01 00 00 18  28 f6 e3 96  a1 30 a2 8a  fe f1 6e 8a
>|   d1 34 d7 c0  df 17 89 dd  0a 00 00 30  00 00 00 01
>|   00 00 00 01  00 00 00 24  00 03 04 01  ce 07 a6 36
>|   00 00 00 18  00 03 00 00  80 04 00 02  80 01 00 01
>|   80 02 70 80  80 05 00 02  00 00 00 14  a3 41 55 11
>|   82 2c 82 fc  1f ac 41 79  f1 aa 83 cb  00 00 00 00
>| next IV:  b1 65 97 eb  c7 c5 b9 82
>| got payload 0x100(ISAKMP_NEXT_HASH) needed: 0x502 opt: 0x200030
>| ***parse ISAKMP Hash Payload:
>|    next payload type: ISAKMP_NEXT_SA
>|    length: 24
>| got payload 0x2(ISAKMP_NEXT_SA) needed: 0x402 opt: 0x200030
>| ***parse ISAKMP Security Association Payload:
>|    next payload type: ISAKMP_NEXT_NONCE
>|    length: 48
>|    DOI: ISAKMP_DOI_IPSEC
>| got payload 0x400(ISAKMP_NEXT_NONCE) needed: 0x400 opt: 0x200030
>| ***parse ISAKMP Nonce Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 20
>| removing 4 bytes of padding
>| **emit ISAKMP Message:
>|    initiator cookie:
>|   3f 38 80 4f  d3 db a5 9f
>|    responder cookie:
>|   c2 36 4a 02  d0 15 cc 47
>|    next payload type: ISAKMP_NEXT_HASH
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_QUICK
>|    flags: ISAKMP_FLAG_ENCRYPTION
>|    message ID:  ed 1b 4c ee
>| HASH(2) computed:
>|   28 f6 e3 96  a1 30 a2 8a  fe f1 6e 8a  d1 34 d7 c0
>|   df 17 89 dd
>| ****parse IPsec DOI SIT:
>|    IPsec DOI SIT: SIT_IDENTITY_ONLY
>| ****parse ISAKMP Proposal Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 36
>|    proposal number: 0
>|    protocol ID: PROTO_IPSEC_ESP
>|    SPI size: 4
>|    number of transforms: 1
>| parsing 4 raw bytes of ISAKMP Proposal Payload into SPI
>| SPI  ce 07 a6 36
>| *****parse ISAKMP Transform Payload (ESP):
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 24
>|    transform number: 0
>|    transform ID: ESP_3DES
>| ******parse ISAKMP IPsec DOI attribute:
>|    af+type: ENCAPSULATION_MODE
>|    length/value: 2
>|    [2 is ENCAPSULATION_MODE_TRANSPORT]
>| ******parse ISAKMP IPsec DOI attribute:
>|    af+type: SA_LIFE_TYPE
>|    length/value: 1
>| ******parse ISAKMP IPsec DOI attribute:
>|    af+type: SA_LIFE_DURATION
>|    length/value: 28800
>| ******parse ISAKMP IPsec DOI attribute:
>|    af+type: AUTH_ALGORITHM
>|    length/value: 2
>| kernel_alg_esp_enc_ok(3,0): alg_id=3, alg_ivlen=8, alg_minbits=192, alg_maxbits=192, res=0, ret=1
>| kernel_alg_esp_enc_keylen():alg_id=3, keylen=24
>| ***emit ISAKMP Hash Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>| emitting 20 zero bytes of HASH into ISAKMP Hash Payload
>| emitting length of ISAKMP Hash Payload: 24
>| HASH(3) computed:  9a 38 6f 60  1a ee 86 27  51 82 59 3e  86 15 71 ef
>| HASH(3) computed:  f6 68 2f 31
>| compute_proto_keymat:needed_len (after ESP enc)=24
>| compute_proto_keymat:needed_len (after ESP auth)=44
>| ESP KEYMAT 
>|   KEYMAT computed:
>|   3d 1e 78 01  32 4d c0 ae  31 8c 95 cd  b1 e0 2c 2b
>|   c2 bb 04 80  c7 22 c5 78  05 89 2a b7  df 5b e4 00
>|   0f 1b 64 04  81 0f 42 1e  27 76 0f 5d
>|   Peer KEYMAT computed:
>|   73 4d 95 93  0c 08 38 32  76 62 86 cf  d5 e2 85 ae
>|   6e d9 4b 87  f3 7c 63 dd  af d4 01 f1  f2 76 c6 73
>|   0d 33 05 63  de de 55 73  c1 fd 92 5e
>| install_ipsec_sa() for #4: inbound and outbound
>| route owner of "v4" erouted: self; eroute owner: self
>| could_route called for v4 (kind=CK_PERMANENT)
>| looking for alg with transid: 3 keylen: 0 auth: 2 
>| checking transid: 11 keylen: 0 auth: 1 
>| checking transid: 11 keylen: 0 auth: 2 
>| checking transid: 2 keylen: 8 auth: 0 
>| checking transid: 2 keylen: 8 auth: 1 
>| checking transid: 2 keylen: 8 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:  73 4d 95 93  0c 08 38 32  76 62 86 cf  d5 e2 85 ae
>| esp enckey:  6e d9 4b 87  f3 7c 63 dd
>| esp authkey:  af d4 01 f1  f2 76 c6 73  0d 33 05 63  de de 55 73
>| esp authkey:  c1 fd 92 5e
>|   using old struct xfrm_algo for XFRM message
>| set up outoing SA, ref=0/4294901761
>| looking for alg with transid: 3 keylen: 0 auth: 2 
>| checking transid: 11 keylen: 0 auth: 1 
>| checking transid: 11 keylen: 0 auth: 2 
>| checking transid: 2 keylen: 8 auth: 0 
>| checking transid: 2 keylen: 8 auth: 1 
>| checking transid: 2 keylen: 8 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:  3d 1e 78 01  32 4d c0 ae  31 8c 95 cd  b1 e0 2c 2b
>| esp enckey:  c2 bb 04 80  c7 22 c5 78
>| esp authkey:  05 89 2a b7  df 5b e4 00  0f 1b 64 04  81 0f 42 1e
>| esp authkey:  27 76 0f 5d
>|   using old struct xfrm_algo for XFRM message
>| set up incoming SA, ref=0/4294901761
>| sr for #4: erouted
>| route owner of "v4" erouted: self; eroute owner: self
>| route_and_eroute with c: v4 (next: none) ero:v4 esr:{(nil)} ro:v4 rosr:{(nil)} and state: 4
>| eroute_connection replace eroute 192.1.2.23/32:0 --0-> 192.1.2.45/32:0 => esp.ce07a636@192.1.2.45 (raw_eroute)
>| raw_eroute result=1 
>| route_and_eroute: firewall_notified: true
>| route_and_eroute: instance "v4", setting eroute_owner {spd=0x2b49aca0a520,sr=0x2b49aca0a520} to #4 (was #3) (newest_ipsec_sa=#3)
>| encrypting:
>|   00 00 00 18  9a 38 6f 60  1a ee 86 27  51 82 59 3e
>|   86 15 71 ef  f6 68 2f 31
>| IV:
>|   b1 65 97 eb  c7 c5 b9 82
>| unpadded size is: 24
>| encrypting 24 using OAKLEY_3DES_CBC
>| NSS: do_3des init start
>| NSS: do_3des init end
>| next IV:  4d 5c e8 b6  6f 60 0c 39
>| emitting length of ISAKMP Message: 52
>| inR1_outI2: instance v4[0], setting newest_ipsec_sa to #4 (was #3) (spd.eroute=#4)
>| complete state transition with STF_OK
>"v4" #4: transition from state STATE_QUICK_I1 to state STATE_QUICK_I2
>| deleting event for #4
>| sending reply packet to 192.1.2.45:500 (from port 500)
>| sending 52 bytes for STATE_QUICK_I1 through eth1:500 to 192.1.2.45:500 (using #4)
>|   3f 38 80 4f  d3 db a5 9f  c2 36 4a 02  d0 15 cc 47
>|   08 10 20 01  ed 1b 4c ee  00 00 00 34  5f 7d 9b db
>|   2c d2 62 77  43 1d 1d 20  e8 a5 9c a2  4d 5c e8 b6
>|   6f 60 0c 39
>| inserting event EVENT_SA_REPLACE, timeout in 27838 seconds for #4
>| event added after event EVENT_LOG_DAILY
>"v4" #4: STATE_QUICK_I2: sent QI2, IPsec SA established transport mode {ESP=>0xce07a636 <0xe116bd19 xfrm=3DES_0-HMAC_SHA1 NATOA=none NATD=none DPD=none}
>| modecfg pull: noquirk policy:push not-client
>| phase 1 is done, looking for phase 2 to unpend
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 10 seconds for #2
>| next event EVENT_RETRANSMIT in 10 seconds for #2
>| 
>| next event EVENT_RETRANSMIT in 0 seconds for #2
>| *time to handle event
>| handling event EVENT_RETRANSMIT
>| event after this is EVENT_PENDING_DDNS in 50 seconds
>| processing connection v6
>| handling event EVENT_RETRANSMIT for 2001:db8:1:2::45 "v6" #2
>| sending 148 bytes for EVENT_RETRANSMIT through eth1:500 to 2001:db8:1:2::45:500 (using #2)
>|   7f 70 da 29  ca d1 bc bf  00 00 00 00  00 00 00 00
>|   01 10 02 00  00 00 00 00  00 00 00 94  0d 00 00 54
>|   00 00 00 01  00 00 00 01  00 00 00 48  00 01 00 02
>|   03 00 00 20  00 01 00 00  80 0b 00 01  80 0c 0e 10
>|   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 05
>|   00 00 00 20  01 01 00 00  80 0b 00 01  80 0c 0e 10
>|   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 02
>|   0d 00 00 10  4f 45 68 79  4c 64 41 43  65 63 66 61
>|   00 00 00 14  af ca d7 13  68 a1 f1 c9  6b 86 96 fc
>|   77 57 01 00
>| inserting event EVENT_RETRANSMIT, timeout in 20 seconds for #2
>| event added at head of queue
>| next event EVENT_RETRANSMIT in 20 seconds for #2
>| 
>| *received 148 bytes from 192.1.2.45:500 on eth1 (port=500)
>|   f4 00 6c 29  85 9c 6f 95  00 00 00 00  00 00 00 00
>|   01 10 02 00  00 00 00 00  00 00 00 94  0d 00 00 54
>|   00 00 00 01  00 00 00 01  00 00 00 48  00 01 00 02
>|   03 00 00 20  00 01 00 00  80 0b 00 01  80 0c 0e 10
>|   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 05
>|   00 00 00 20  01 01 00 00  80 0b 00 01  80 0c 0e 10
>|   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 02
>|   0d 00 00 10  4f 45 68 79  4c 64 41 43  65 63 66 61
>|   00 00 00 14  af ca d7 13  68 a1 f1 c9  6b 86 96 fc
>|   77 57 01 00
>| **parse ISAKMP Message:
>|    initiator cookie:
>|   f4 00 6c 29  85 9c 6f 95
>|    responder cookie:
>|   00 00 00 00  00 00 00 00
>|    next payload type: ISAKMP_NEXT_SA
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_IDPROT
>|    flags: none
>|    message ID:  00 00 00 00
>|    length: 148
>|  processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
>| got payload 0x2(ISAKMP_NEXT_SA) needed: 0x2 opt: 0x2080
>| ***parse ISAKMP Security Association Payload:
>|    next payload type: ISAKMP_NEXT_VID
>|    length: 84
>|    DOI: ISAKMP_DOI_IPSEC
>| got payload 0x2000(ISAKMP_NEXT_VID) needed: 0x0 opt: 0x2080
>| ***parse ISAKMP Vendor ID Payload:
>|    next payload type: ISAKMP_NEXT_VID
>|    length: 16
>| got payload 0x2000(ISAKMP_NEXT_VID) needed: 0x0 opt: 0x2080
>| ***parse ISAKMP Vendor ID Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 20
>packet from 192.1.2.45:500: received Vendor ID payload [Openswan (this version) 2.6.32 ]
>packet from 192.1.2.45:500: received Vendor ID payload [Dead Peer Detection]
>| find_host_connection2 called from main_inI1_outR1, me=192.1.2.23:500 him=192.1.2.45:500 policy=none
>| find_host_pair: comparing to 192.1.2.23:500 192.1.2.45:500 
>| find_host_pair_conn (find_host_connection2): 192.1.2.23:500 192.1.2.45:500 -> hp:v4 
>| find_host_connection2 returns v4
>| creating state object #5 at 0x2b49aca57b60
>| processing connection v4
>| ICOOKIE:  f4 00 6c 29  85 9c 6f 95
>| RCOOKIE:  94 4a f0 cc  d0 a3 ed 33
>| state hash entry 9
>| inserting state object #5 on chain 9
>| inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #5
>| event added at head of queue
>"v4" #5: responding to Main Mode
>| **emit ISAKMP Message:
>|    initiator cookie:
>|   f4 00 6c 29  85 9c 6f 95
>|    responder cookie:
>|   94 4a f0 cc  d0 a3 ed 33
>|    next payload type: ISAKMP_NEXT_SA
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_IDPROT
>|    flags: none
>|    message ID:  00 00 00 00
>| ***emit ISAKMP Security Association Payload:
>|    next payload type: ISAKMP_NEXT_VID
>|    DOI: ISAKMP_DOI_IPSEC
>| ****parse IPsec DOI SIT:
>|    IPsec DOI SIT: SIT_IDENTITY_ONLY
>| ****parse ISAKMP Proposal Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 72
>|    proposal number: 0
>|    protocol ID: PROTO_ISAKMP
>|    SPI size: 0
>|    number of transforms: 2
>| *****parse ISAKMP Transform Payload (ISAKMP):
>|    next payload type: ISAKMP_NEXT_T
>|    length: 32
>|    transform number: 0
>|    transform ID: KEY_IKE
>| ******parse ISAKMP Oakley attribute:
>|    af+type: OAKLEY_LIFE_TYPE
>|    length/value: 1
>|    [1 is OAKLEY_LIFE_SECONDS]
>| ******parse ISAKMP Oakley attribute:
>|    af+type: OAKLEY_LIFE_DURATION
>|    length/value: 3600
>| ******parse ISAKMP Oakley attribute:
>|    af+type: OAKLEY_ENCRYPTION_ALGORITHM
>|    length/value: 5
>|    [5 is OAKLEY_3DES_CBC]
>| ike_alg_enc_ok(ealg=5,key_len=0): blocksize=8, keyminlen=192, keydeflen=192, keymaxlen=192, ret=1
>| ******parse ISAKMP Oakley attribute:
>|    af+type: OAKLEY_HASH_ALGORITHM
>|    length/value: 2
>|    [2 is OAKLEY_SHA1]
>| ******parse ISAKMP Oakley attribute:
>|    af+type: OAKLEY_AUTHENTICATION_METHOD
>|    length/value: 1
>|    [1 is OAKLEY_PRESHARED_KEY]
>| started looking for secret for 192.1.2.23->192.1.2.45 of kind PPK_PSK
>| actually looking for secret for 192.1.2.23->192.1.2.45 of kind PPK_PSK
>| line 2: key type PPK_PSK(192.1.2.23) to type PPK_PSK 
>| 1: compared key 2001:db8:1:2::45 to 192.1.2.23 / 192.1.2.45 -> 0
>| 2: compared key 2001:db8:1:2::23 to 192.1.2.23 / 192.1.2.45 -> 0
>| line 2: match=0 
>| line 1: key type PPK_PSK(192.1.2.23) to type PPK_PSK 
>| 1: compared key 192.1.2.23 to 192.1.2.23 / 192.1.2.45 -> 8
>| 2: compared key 192.1.2.45 to 192.1.2.23 / 192.1.2.45 -> 12
>| line 1: match=12 
>| best_match 0>12 best=0x2b49aca0d130 (line=1)
>| concluding with best_match=12 best=0x2b49aca0d130 (lineno=1)
>| ******parse ISAKMP Oakley attribute:
>|    af+type: OAKLEY_GROUP_DESCRIPTION
>|    length/value: 5
>|    [5 is OAKLEY_GROUP_MODP1536]
>| Oakley Transform 0 accepted
>| ****emit IPsec DOI SIT:
>|    IPsec DOI SIT: SIT_IDENTITY_ONLY
>| ****emit ISAKMP Proposal Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    proposal number: 0
>|    protocol ID: PROTO_ISAKMP
>|    SPI size: 0
>|    number of transforms: 1
>| *****emit ISAKMP Transform Payload (ISAKMP):
>|    next payload type: ISAKMP_NEXT_NONE
>|    transform number: 0
>|    transform ID: KEY_IKE
>| emitting 24 raw bytes of attributes into ISAKMP Transform Payload (ISAKMP)
>| attributes  80 0b 00 01  80 0c 0e 10  80 01 00 05  80 02 00 02
>| attributes  80 03 00 01  80 04 00 05
>| emitting length of ISAKMP Transform Payload (ISAKMP): 32
>| emitting length of ISAKMP Proposal Payload: 40
>| emitting length of ISAKMP Security Association Payload: 52
>| ***emit ISAKMP Vendor ID Payload:
>|    next payload type: ISAKMP_NEXT_VID
>| emitting 12 raw bytes of Vendor ID into ISAKMP Vendor ID Payload
>| Vendor ID  4f 45 68 79  4c 64 41 43  65 63 66 61
>| emitting length of ISAKMP Vendor ID Payload: 16
>| out_vendorid(): sending [Dead Peer Detection]
>| ***emit ISAKMP Vendor ID Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>| emitting 16 raw bytes of V_ID into ISAKMP Vendor ID Payload
>| V_ID  af ca d7 13  68 a1 f1 c9  6b 86 96 fc  77 57 01 00
>| emitting length of ISAKMP Vendor ID Payload: 20
>| sender checking NAT-t: 0 and 0
>| emitting length of ISAKMP Message: 116
>| peer supports dpd
>| complete state transition with STF_OK
>"v4" #5: transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
>| deleting event for #5
>| sending reply packet to 192.1.2.45:500 (from port 500)
>| sending 116 bytes for STATE_MAIN_R0 through eth1:500 to 192.1.2.45:500 (using #5)
>|   f4 00 6c 29  85 9c 6f 95  94 4a f0 cc  d0 a3 ed 33
>|   01 10 02 00  00 00 00 00  00 00 00 74  0d 00 00 34
>|   00 00 00 01  00 00 00 01  00 00 00 28  00 01 00 01
>|   00 00 00 20  00 01 00 00  80 0b 00 01  80 0c 0e 10
>|   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 05
>|   0d 00 00 10  4f 45 68 79  4c 64 41 43  65 63 66 61
>|   00 00 00 14  af ca d7 13  68 a1 f1 c9  6b 86 96 fc
>|   77 57 01 00
>| inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #5
>| event added at head of queue
>"v4" #5: STATE_MAIN_R1: sent MR1, expecting MI2
>| modecfg pull: noquirk policy:push not-client
>| phase 1 is done, looking for phase 2 to unpend
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 10 seconds for #5
>| next event EVENT_RETRANSMIT in 10 seconds for #5
>| 
>| *received 244 bytes from 192.1.2.45:500 on eth1 (port=500)
>|   f4 00 6c 29  85 9c 6f 95  94 4a f0 cc  d0 a3 ed 33
>|   04 10 02 00  00 00 00 00  00 00 00 f4  0a 00 00 c4
>|   39 7c c4 44  36 f8 b5 02  36 00 ba 89  50 18 0d 21
>|   d5 34 c2 91  55 9b ff 32  13 ba ca 3b  6e 79 58 93
>|   91 9c 44 f1  75 38 c9 8a  1b 35 a3 c2  c5 dc d9 f4
>|   1c 90 31 a6  5a dd 90 92  2d 7a a6 d1  6d 25 51 5d
>|   6e ab 06 a7  d1 2a f1 59  52 26 f4 e2  3c 23 8b b4
>|   d3 f4 aa b3  94 df b5 14  ac cf cd ac  72 2b 49 88
>|   8d 87 39 5d  2a 03 ec c4  26 ff e2 48  c5 71 8f 3b
>|   f2 e1 d5 a3  4e 2c c6 46  68 01 3f 66  83 ca cb 80
>|   95 c5 72 b8  d9 d8 e4 4a  ed 5e 30 ed  ae ec a8 7b
>|   a1 da 62 62  ca fd fd 03  89 2c cc cc  52 88 5d dd
>|   91 40 f5 09  f8 c7 d9 f2  bf d6 62 43  fd 67 95 eb
>|   6a 2a 9f 9e  a3 1f da 13  dc 88 68 cc  1f a8 c5 22
>|   00 00 00 14  b4 a7 19 8c  41 a9 0d 87  72 7a e9 e9
>|   a3 6f 2d 72
>| **parse ISAKMP Message:
>|    initiator cookie:
>|   f4 00 6c 29  85 9c 6f 95
>|    responder cookie:
>|   94 4a f0 cc  d0 a3 ed 33
>|    next payload type: ISAKMP_NEXT_KE
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_IDPROT
>|    flags: none
>|    message ID:  00 00 00 00
>|    length: 244
>|  processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
>| ICOOKIE:  f4 00 6c 29  85 9c 6f 95
>| RCOOKIE:  94 4a f0 cc  d0 a3 ed 33
>| state hash entry 9
>| v1 peer and cookies match on #5, provided msgid 00000000 vs 00000000
>| v1 state object #5 found, in STATE_MAIN_R1
>| processing connection v4
>| got payload 0x10(ISAKMP_NEXT_KE) needed: 0x410 opt: 0x102080
>| ***parse ISAKMP Key Exchange Payload:
>|    next payload type: ISAKMP_NEXT_NONCE
>|    length: 196
>| got payload 0x400(ISAKMP_NEXT_NONCE) needed: 0x400 opt: 0x102080
>| ***parse ISAKMP Nonce Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 20
>| DH public value received:
>|   39 7c c4 44  36 f8 b5 02  36 00 ba 89  50 18 0d 21
>|   d5 34 c2 91  55 9b ff 32  13 ba ca 3b  6e 79 58 93
>|   91 9c 44 f1  75 38 c9 8a  1b 35 a3 c2  c5 dc d9 f4
>|   1c 90 31 a6  5a dd 90 92  2d 7a a6 d1  6d 25 51 5d
>|   6e ab 06 a7  d1 2a f1 59  52 26 f4 e2  3c 23 8b b4
>|   d3 f4 aa b3  94 df b5 14  ac cf cd ac  72 2b 49 88
>|   8d 87 39 5d  2a 03 ec c4  26 ff e2 48  c5 71 8f 3b
>|   f2 e1 d5 a3  4e 2c c6 46  68 01 3f 66  83 ca cb 80
>|   95 c5 72 b8  d9 d8 e4 4a  ed 5e 30 ed  ae ec a8 7b
>|   a1 da 62 62  ca fd fd 03  89 2c cc cc  52 88 5d dd
>|   91 40 f5 09  f8 c7 d9 f2  bf d6 62 43  fd 67 95 eb
>|   6a 2a 9f 9e  a3 1f da 13  dc 88 68 cc  1f a8 c5 22
>| inI2: checking NAT-t: 0 and 0
>| 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
>| asking helper 0 to do build_kenonce op on seq: 5 (len=2776, pcw_work=1)
>| crypto helper write of request: cnt=2776<wlen=2776.  
>| deleting event for #5
>| inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #5
>| event added after event EVENT_PENDING_PHASE2
>| complete state transition with STF_SUSPEND
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 20 seconds for #2
>| next event EVENT_RETRANSMIT in 20 seconds for #2
>| helper 0 read 2768+4/2776 bytes fd: 10
>| helper 0 doing build_kenonce op id: 5
>| 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 e4 5b 3d  c2 00 7c b8  a1 63 bf 05
>|   98 da 48 36  1c 55 d3 9a  69 16 3f a8  fd 24 cf 5f
>|   83 65 5d 23  dc a3 ad 96  1c 62 f3 56  20 85 52 bb
>|   9e d5 29 07  70 96 96 6d  67 0c 35 4e  4a bc 98 04
>|   f1 74 6c 08  ca 23 73 27  ff ff ff ff  ff ff ff ff
>| NSS: Value of base:
>|   02
>| NSS: generated dh priv and pub keys: 192 
>| NSS: Local DH secret:
>|   20 ce a5 ac  49 2b 00 00
>| NSS: Public DH value sent(computed in NSS):
>|   09 8a 0e 95  b1 b5 56 88  71 41 68 17  f2 19 d3 f4
>|   63 44 8d 62  f2 5b 2a d9  54 5f 7f 19  85 b3 64 f8
>|   68 46 8d e8  60 cb 90 c9  ac 97 cc e0  6e b8 2b ca
>|   a8 63 60 e2  f9 28 1a a4  c3 44 26 50  e4 ab 0c e1
>|   f9 5e 6d d3  bd c9 03 90  29 45 79 51  f7 74 70 fd
>|   1b a6 89 1f  17 9b 1a 23  9d 0c ba b6  30 58 d7 d1
>|   a4 64 39 56  5f 89 f8 3b  3d 48 85 a3  d2 a2 ca 34
>|   0c e2 c9 45  81 2e 6a e9  cd 14 1d 6e  24 ca b2 14
>|   a5 82 15 1e  1a 10 f0 ca  3a 0c b5 2a  9b c2 f1 19
>|   f6 e9 56 3f  a8 ff 3b 10  bb 4b 1a 85  da 8d 49 22
>|   1a f5 0b d9  d0 0d 04 91  d8 75 f6 80  05 3a 6f e3
>|   db 15 2a a1  be f7 e4 8a  8f 34 68 db  bb 48 48 73
>| NSS: Local DH public value (pointer):
>|   10 c6 a5 ac  49 2b 00 00
>| Generated nonce:
>|   e6 9b e7 a7  44 33 b4 72  68 6c a6 3b  22 61 7a bb
>| 
>| helper 0 has finished work (cnt now 1)
>| helper 0 replies to id: q#5
>| calling callback function 0x2b49ac6d80f0
>| main inI2_outR2: calculated ke+nonce, sending R2
>| processing connection v4
>| **emit ISAKMP Message:
>|    initiator cookie:
>|   f4 00 6c 29  85 9c 6f 95
>|    responder cookie:
>|   94 4a f0 cc  d0 a3 ed 33
>|    next payload type: ISAKMP_NEXT_KE
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_IDPROT
>|    flags: none
>|    message ID:  00 00 00 00
>| saving DH priv (local secret) and pub key into state struc
>| ***emit ISAKMP Key Exchange Payload:
>|    next payload type: ISAKMP_NEXT_NONCE
>| emitting 192 raw bytes of keyex value into ISAKMP Key Exchange Payload
>| keyex value  09 8a 0e 95  b1 b5 56 88  71 41 68 17  f2 19 d3 f4
>| keyex value  63 44 8d 62  f2 5b 2a d9  54 5f 7f 19  85 b3 64 f8
>| keyex value  68 46 8d e8  60 cb 90 c9  ac 97 cc e0  6e b8 2b ca
>| keyex value  a8 63 60 e2  f9 28 1a a4  c3 44 26 50  e4 ab 0c e1
>| keyex value  f9 5e 6d d3  bd c9 03 90  29 45 79 51  f7 74 70 fd
>| keyex value  1b a6 89 1f  17 9b 1a 23  9d 0c ba b6  30 58 d7 d1
>| keyex value  a4 64 39 56  5f 89 f8 3b  3d 48 85 a3  d2 a2 ca 34
>| keyex value  0c e2 c9 45  81 2e 6a e9  cd 14 1d 6e  24 ca b2 14
>| keyex value  a5 82 15 1e  1a 10 f0 ca  3a 0c b5 2a  9b c2 f1 19
>| keyex value  f6 e9 56 3f  a8 ff 3b 10  bb 4b 1a 85  da 8d 49 22
>| keyex value  1a f5 0b d9  d0 0d 04 91  d8 75 f6 80  05 3a 6f e3
>| keyex value  db 15 2a a1  be f7 e4 8a  8f 34 68 db  bb 48 48 73
>| emitting length of ISAKMP Key Exchange Payload: 196
>| ***emit ISAKMP Nonce Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>| emitting 16 raw bytes of Nr into ISAKMP Nonce Payload
>| Nr  e6 9b e7 a7  44 33 b4 72  68 6c a6 3b  22 61 7a bb
>| emitting length of ISAKMP Nonce Payload: 20
>| emitting length of ISAKMP Message: 244
>| main inI2_outR2: starting async DH calculation (group=5)
>| started looking for secret for 192.1.2.23->192.1.2.45 of kind PPK_PSK
>| actually looking for secret for 192.1.2.23->192.1.2.45 of kind PPK_PSK
>| line 2: key type PPK_PSK(192.1.2.23) to type PPK_PSK 
>| 1: compared key 2001:db8:1:2::45 to 192.1.2.23 / 192.1.2.45 -> 0
>| 2: compared key 2001:db8:1:2::23 to 192.1.2.23 / 192.1.2.45 -> 0
>| line 2: match=0 
>| line 1: key type PPK_PSK(192.1.2.23) to type PPK_PSK 
>| 1: compared key 192.1.2.23 to 192.1.2.23 / 192.1.2.45 -> 8
>| 2: compared key 192.1.2.45 to 192.1.2.23 / 192.1.2.45 -> 12
>| line 1: match=12 
>| best_match 0>12 best=0x2b49aca0d130 (line=1)
>| concluding with best_match=12 best=0x2b49aca0d130 (lineno=1)
>| parent1 type: 7 group: 5 len: 2776 
>| Copying DH pub key pointer to be sent to a thread helper
>| 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
>| asking helper 0 to do compute dh+iv op on seq: 6 (len=2776, pcw_work=1)
>| crypto helper write of request: cnt=2776<wlen=2776.  
>| deleting event for #5
>| inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #5
>| event added after event EVENT_PENDING_PHASE2
>| started dh_secretiv, returned: stf=STF_SUSPEND 
>| complete state transition with STF_OK
>"v4" #5: transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
>| deleting event for #5
>| sending reply packet to 192.1.2.45:500 (from port 500)
>| sending 244 bytes for STATE_MAIN_R1 through eth1:500 to 192.1.2.45:500 (using #5)
>|   f4 00 6c 29  85 9c 6f 95  94 4a f0 cc  d0 a3 ed 33
>|   04 10 02 00  00 00 00 00  00 00 00 f4  0a 00 00 c4
>|   09 8a 0e 95  b1 b5 56 88  71 41 68 17  f2 19 d3 f4
>|   63 44 8d 62  f2 5b 2a d9  54 5f 7f 19  85 b3 64 f8
>|   68 46 8d e8  60 cb 90 c9  ac 97 cc e0  6e b8 2b ca
>|   a8 63 60 e2  f9 28 1a a4  c3 44 26 50  e4 ab 0c e1
>|   f9 5e 6d d3  bd c9 03 90  29 45 79 51  f7 74 70 fd
>|   1b a6 89 1f  17 9b 1a 23  9d 0c ba b6  30 58 d7 d1
>|   a4 64 39 56  5f 89 f8 3b  3d 48 85 a3  d2 a2 ca 34
>|   0c e2 c9 45  81 2e 6a e9  cd 14 1d 6e  24 ca b2 14
>|   a5 82 15 1e  1a 10 f0 ca  3a 0c b5 2a  9b c2 f1 19
>|   f6 e9 56 3f  a8 ff 3b 10  bb 4b 1a 85  da 8d 49 22
>|   1a f5 0b d9  d0 0d 04 91  d8 75 f6 80  05 3a 6f e3
>|   db 15 2a a1  be f7 e4 8a  8f 34 68 db  bb 48 48 73
>|   00 00 00 14  e6 9b e7 a7  44 33 b4 72  68 6c a6 3b
>|   22 61 7a bb
>| inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #5
>| event added at head of queue
>"v4" #5: STATE_MAIN_R2: sent MR2, expecting MI3
>| modecfg pull: noquirk policy:push not-client
>| phase 1 is done, looking for phase 2 to unpend
>| * processed 1 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 10 seconds for #5
>| next event EVENT_RETRANSMIT in 10 seconds for #5
>| helper 0 read 2768+4/2776 bytes fd: 10
>| helper 0 doing compute dh+iv op id: 6
>| peer's g:   39 7c c4 44  36 f8 b5 02  36 00 ba 89  50 18 0d 21
>| peer's g:   d5 34 c2 91  55 9b ff 32  13 ba ca 3b  6e 79 58 93
>| peer's g:   91 9c 44 f1  75 38 c9 8a  1b 35 a3 c2  c5 dc d9 f4
>| peer's g:   1c 90 31 a6  5a dd 90 92  2d 7a a6 d1  6d 25 51 5d
>| peer's g:   6e ab 06 a7  d1 2a f1 59  52 26 f4 e2  3c 23 8b b4
>| peer's g:   d3 f4 aa b3  94 df b5 14  ac cf cd ac  72 2b 49 88
>| peer's g:   8d 87 39 5d  2a 03 ec c4  26 ff e2 48  c5 71 8f 3b
>| peer's g:   f2 e1 d5 a3  4e 2c c6 46  68 01 3f 66  83 ca cb 80
>| peer's g:   95 c5 72 b8  d9 d8 e4 4a  ed 5e 30 ed  ae ec a8 7b
>| peer's g:   a1 da 62 62  ca fd fd 03  89 2c cc cc  52 88 5d dd
>| peer's g:   91 40 f5 09  f8 c7 d9 f2  bf d6 62 43  fd 67 95 eb
>| peer's g:   6a 2a 9f 9e  a3 1f da 13  dc 88 68 cc  1f a8 c5 22
>| Started DH shared-secret computation in NSS: 
>| Dropped no leading zeros 192
>| calc_dh_shared(): time elapsed (OAKLEY_GROUP_MODP1536): 354 usec
>| DH shared-secret pointer:
>|   80 e5 a4 ac  49 2b 00 00
>| NSS: skeyid inputs (pss+NI+NR+shared) hasher: oakley_sha
>| shared-secret:   80 e5 a4 ac  49 2b 00 00
>| ni:   b4 a7 19 8c  41 a9 0d 87  72 7a e9 e9  a3 6f 2d 72
>| nr:   e6 9b e7 a7  44 33 b4 72  68 6c a6 3b  22 61 7a bb
>| NSS: st_skeyid in skeyid_preshared(): 
>|   f0 65 a4 ac  49 2b 00 00
>| NSS: Started key computation 
>| NSS: enc keysize=24 
>| NSS: Freed 25-39 symkeys 
>| NSS: copied skeyid_d_chunk 
>| NSS: copied skeyid_a_chunk 
>| NSS: copied skeyid_e_chunk 
>| NSS: copied enc_key_chunk 
>| NSS: Freed symkeys 1-23 
>| NSS: Freed padding chunks 
>| DH_i:  39 7c c4 44  36 f8 b5 02  36 00 ba 89  50 18 0d 21
>| DH_i:  d5 34 c2 91  55 9b ff 32  13 ba ca 3b  6e 79 58 93
>| DH_i:  91 9c 44 f1  75 38 c9 8a  1b 35 a3 c2  c5 dc d9 f4
>| DH_i:  1c 90 31 a6  5a dd 90 92  2d 7a a6 d1  6d 25 51 5d
>| DH_i:  6e ab 06 a7  d1 2a f1 59  52 26 f4 e2  3c 23 8b b4
>| DH_i:  d3 f4 aa b3  94 df b5 14  ac cf cd ac  72 2b 49 88
>| DH_i:  8d 87 39 5d  2a 03 ec c4  26 ff e2 48  c5 71 8f 3b
>| DH_i:  f2 e1 d5 a3  4e 2c c6 46  68 01 3f 66  83 ca cb 80
>| DH_i:  95 c5 72 b8  d9 d8 e4 4a  ed 5e 30 ed  ae ec a8 7b
>| DH_i:  a1 da 62 62  ca fd fd 03  89 2c cc cc  52 88 5d dd
>| DH_i:  91 40 f5 09  f8 c7 d9 f2  bf d6 62 43  fd 67 95 eb
>| DH_i:  6a 2a 9f 9e  a3 1f da 13  dc 88 68 cc  1f a8 c5 22
>| DH_r:  09 8a 0e 95  b1 b5 56 88  71 41 68 17  f2 19 d3 f4
>| DH_r:  63 44 8d 62  f2 5b 2a d9  54 5f 7f 19  85 b3 64 f8
>| DH_r:  68 46 8d e8  60 cb 90 c9  ac 97 cc e0  6e b8 2b ca
>| DH_r:  a8 63 60 e2  f9 28 1a a4  c3 44 26 50  e4 ab 0c e1
>| DH_r:  f9 5e 6d d3  bd c9 03 90  29 45 79 51  f7 74 70 fd
>| DH_r:  1b a6 89 1f  17 9b 1a 23  9d 0c ba b6  30 58 d7 d1
>| DH_r:  a4 64 39 56  5f 89 f8 3b  3d 48 85 a3  d2 a2 ca 34
>| DH_r:  0c e2 c9 45  81 2e 6a e9  cd 14 1d 6e  24 ca b2 14
>| DH_r:  a5 82 15 1e  1a 10 f0 ca  3a 0c b5 2a  9b c2 f1 19
>| DH_r:  f6 e9 56 3f  a8 ff 3b 10  bb 4b 1a 85  da 8d 49 22
>| DH_r:  1a f5 0b d9  d0 0d 04 91  d8 75 f6 80  05 3a 6f e3
>| DH_r:  db 15 2a a1  be f7 e4 8a  8f 34 68 db  bb 48 48 73
>| end of IV generation 
>| 
>| helper 0 has finished work (cnt now 1)
>| helper 0 replies to id: q#6
>| calling callback function 0x2b49ac6daf90
>| main inI2_outR2: calculated DH finished
>| processing connection v4
>| * processed 1 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 10 seconds for #5
>| next event EVENT_RETRANSMIT in 10 seconds for #5
>| 
>| *received 68 bytes from 192.1.2.45:500 on eth1 (port=500)
>|   f4 00 6c 29  85 9c 6f 95  94 4a f0 cc  d0 a3 ed 33
>|   05 10 02 01  00 00 00 00  00 00 00 44  15 04 c8 b3
>|   4e 18 ed 0a  57 15 e8 01  2b 74 ec 39  e7 cc 79 b3
>|   b0 40 b7 90  eb 32 c3 f2  01 65 81 ca  21 08 df 33
>|   5e 82 e1 fc
>| **parse ISAKMP Message:
>|    initiator cookie:
>|   f4 00 6c 29  85 9c 6f 95
>|    responder cookie:
>|   94 4a f0 cc  d0 a3 ed 33
>|    next payload type: ISAKMP_NEXT_ID
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_IDPROT
>|    flags: ISAKMP_FLAG_ENCRYPTION
>|    message ID:  00 00 00 00
>|    length: 68
>|  processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
>| ICOOKIE:  f4 00 6c 29  85 9c 6f 95
>| RCOOKIE:  94 4a f0 cc  d0 a3 ed 33
>| state hash entry 9
>| v1 peer and cookies match on #5, provided msgid 00000000 vs 00000000
>| v1 state object #5 found, in STATE_MAIN_R2
>| processing connection v4
>| received encrypted packet from 192.1.2.45:500
>| decrypting 40 bytes using algorithm OAKLEY_3DES_CBC
>| NSS: do_3des init start
>| NSS: do_3des init end
>| decrypted:
>|   08 00 00 0c  01 00 00 00  c0 01 02 2d  00 00 00 18
>|   39 2e 11 5c  ad b9 b4 4e  ec d5 56 e9  0d e7 d5 c6
>|   12 d4 9a 3a  00 00 00 00
>| next IV:  21 08 df 33  5e 82 e1 fc
>| got payload 0x20(ISAKMP_NEXT_ID) needed: 0x120 opt: 0x2080
>| ***parse ISAKMP Identification Payload:
>|    next payload type: ISAKMP_NEXT_HASH
>|    length: 12
>|    ID type: ID_IPV4_ADDR
>|    DOI specific A: 0
>|    DOI specific B: 0
>|      obj:   c0 01 02 2d
>| got payload 0x100(ISAKMP_NEXT_HASH) needed: 0x100 opt: 0x2080
>| ***parse ISAKMP Hash Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 24
>| removing 4 bytes of padding
>"v4" #5: Main mode peer ID is ID_IPV4_ADDR: '192.1.2.45'
>| refine_connection: starting with v4
>| started looking for secret for 192.1.2.23->192.1.2.45 of kind PPK_PSK
>| actually looking for secret for 192.1.2.23->192.1.2.45 of kind PPK_PSK
>| line 2: key type PPK_PSK(192.1.2.23) to type PPK_PSK 
>| 1: compared key 2001:db8:1:2::45 to 192.1.2.23 / 192.1.2.45 -> 0
>| 2: compared key 2001:db8:1:2::23 to 192.1.2.23 / 192.1.2.45 -> 0
>| line 2: match=0 
>| line 1: key type PPK_PSK(192.1.2.23) to type PPK_PSK 
>| 1: compared key 192.1.2.23 to 192.1.2.23 / 192.1.2.45 -> 8
>| 2: compared key 192.1.2.45 to 192.1.2.23 / 192.1.2.45 -> 12
>| line 1: match=12 
>| best_match 0>12 best=0x2b49aca0d130 (line=1)
>| concluding with best_match=12 best=0x2b49aca0d130 (lineno=1)
>|    match_id a=192.1.2.45
>|             b=192.1.2.45
>|    results  matched
>|   trusted_ca called with a=(empty) b=(empty)
>| refine_connection: checking v4 against v4, best=(none) with match=1(id=1/ca=1/reqca=1)
>| refine_connection: checked v4 against v4, now for see if best
>| started looking for secret for 192.1.2.23->192.1.2.45 of kind PPK_PSK
>| actually looking for secret for 192.1.2.23->192.1.2.45 of kind PPK_PSK
>| line 2: key type PPK_PSK(192.1.2.23) to type PPK_PSK 
>| 1: compared key 2001:db8:1:2::45 to 192.1.2.23 / 192.1.2.45 -> 0
>| 2: compared key 2001:db8:1:2::23 to 192.1.2.23 / 192.1.2.45 -> 0
>| line 2: match=0 
>| line 1: key type PPK_PSK(192.1.2.23) to type PPK_PSK 
>| 1: compared key 192.1.2.23 to 192.1.2.23 / 192.1.2.45 -> 8
>| 2: compared key 192.1.2.45 to 192.1.2.23 / 192.1.2.45 -> 12
>| line 1: match=12 
>| best_match 0>12 best=0x2b49aca0d130 (line=1)
>| concluding with best_match=12 best=0x2b49aca0d130 (lineno=1)
>| offered CA: '%none'
>| hashing 80 bytes of SA
>| authentication succeeded
>| thinking about whether to send my certificate:
>|   I have RSA key: OAKLEY_PRESHARED_KEY cert.type: CERT_NONE 
>|   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 ISAKMP Message:
>|    initiator cookie:
>|   f4 00 6c 29  85 9c 6f 95
>|    responder cookie:
>|   94 4a f0 cc  d0 a3 ed 33
>|    next payload type: ISAKMP_NEXT_ID
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_IDPROT
>|    flags: ISAKMP_FLAG_ENCRYPTION
>|    message ID:  00 00 00 00
>| ***emit ISAKMP Identification Payload (IPsec DOI):
>|    next payload type: ISAKMP_NEXT_HASH
>|    ID type: ID_IPV4_ADDR
>|    Protocol ID: 0
>|    port: 0
>| emitting 4 raw bytes of my identity into ISAKMP Identification Payload (IPsec DOI)
>| my identity  c0 01 02 17
>| emitting length of ISAKMP Identification Payload (IPsec DOI): 12
>| hashing 80 bytes of SA
>| ***emit ISAKMP Hash Payload:
>|    next payload type: ISAKMP_NEXT_VID
>| emitting 20 raw bytes of HASH_R into ISAKMP Hash Payload
>| HASH_R  8e 0c 2e c1  71 0f b7 7f  28 de 49 b0  0a 3d 18 60
>| HASH_R  17 4b 46 b0
>| emitting length of ISAKMP Hash Payload: 24
>| out_vendorid(): sending [CAN-IKEv2]
>| ***emit ISAKMP Vendor ID Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>| emitting 5 raw bytes of V_ID into ISAKMP Vendor ID Payload
>| V_ID  49 4b 45 76  32
>| emitting length of ISAKMP Vendor ID Payload: 9
>| encrypting:
>|   08 00 00 0c  01 00 00 00  c0 01 02 17  0d 00 00 18
>|   8e 0c 2e c1  71 0f b7 7f  28 de 49 b0  0a 3d 18 60
>|   17 4b 46 b0  00 00 00 09  49 4b 45 76  32
>| IV:
>|   21 08 df 33  5e 82 e1 fc
>| unpadded size is: 45
>| emitting 3 zero bytes of encryption padding into ISAKMP Message
>| encrypting 48 using OAKLEY_3DES_CBC
>| NSS: do_3des init start
>| NSS: do_3des init end
>| next IV:  bd c3 e7 95  db 5d fc 9a
>| emitting length of ISAKMP Message: 76
>| last encrypted block of Phase 1:
>|   bd c3 e7 95  db 5d fc 9a
>| complete state transition with STF_OK
>"v4" #5: transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
>| deleting event for #5
>| sending reply packet to 192.1.2.45:500 (from port 500)
>| sending 76 bytes for STATE_MAIN_R2 through eth1:500 to 192.1.2.45:500 (using #5)
>|   f4 00 6c 29  85 9c 6f 95  94 4a f0 cc  d0 a3 ed 33
>|   05 10 02 01  00 00 00 00  00 00 00 4c  53 2d 37 c6
>|   25 74 2c 87  10 0b e0 e9  f1 13 71 6d  0d a1 97 19
>|   c5 f4 11 45  24 c2 f1 de  58 44 0f 3e  d6 4c 0d ab
>|   d4 e7 82 96  bd c3 e7 95  db 5d fc 9a
>| inserting event EVENT_SA_REPLACE, timeout in 3330 seconds for #5
>| event added after event EVENT_SA_REPLACE for #1
>"v4" #5: STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY cipher=oakley_3des_cbc_192 prf=oakley_sha group=modp1536}
>| modecfg pull: noquirk policy:push not-client
>| phase 1 is done, looking for phase 2 to unpend
>| unpending state #5
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 19 seconds for #2
>| next event EVENT_RETRANSMIT in 19 seconds for #2
>| 
>| *received 124 bytes from 192.1.2.45:500 on eth1 (port=500)
>|   f4 00 6c 29  85 9c 6f 95  94 4a f0 cc  d0 a3 ed 33
>|   08 10 20 01  c1 a7 d8 34  00 00 00 7c  28 03 1f 7a
>|   93 28 e4 29  17 97 b1 e4  58 b8 50 42  6f 23 45 35
>|   e5 49 26 69  ea de b8 be  f0 e9 fa 52  7f d1 75 4a
>|   c6 02 66 f7  c6 6b 3c 2e  06 04 d0 64  9f b7 cf b4
>|   23 bf fe bf  04 f5 a1 0a  c6 eb d6 90  63 6b 08 04
>|   89 10 74 f5  2b 21 4e 0f  8d c3 1c 9c  41 f9 7b 83
>|   70 97 09 12  3a 6f 1b 28  d2 7c c1 c5
>| **parse ISAKMP Message:
>|    initiator cookie:
>|   f4 00 6c 29  85 9c 6f 95
>|    responder cookie:
>|   94 4a f0 cc  d0 a3 ed 33
>|    next payload type: ISAKMP_NEXT_HASH
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_QUICK
>|    flags: ISAKMP_FLAG_ENCRYPTION
>|    message ID:  c1 a7 d8 34
>|    length: 124
>|  processing version=1.0 packet with exchange type=ISAKMP_XCHG_QUICK (32)
>| ICOOKIE:  f4 00 6c 29  85 9c 6f 95
>| RCOOKIE:  94 4a f0 cc  d0 a3 ed 33
>| state hash entry 9
>| v1 peer and cookies match on #5, provided msgid c1a7d834 vs 00000000
>| v1 state object not found
>| ICOOKIE:  f4 00 6c 29  85 9c 6f 95
>| RCOOKIE:  94 4a f0 cc  d0 a3 ed 33
>| state hash entry 9
>| v1 peer and cookies match on #5, provided msgid 00000000 vs 00000000
>| v1 state object #5 found, in STATE_MAIN_R3
>| processing connection v4
>| last Phase 1 IV:  bd c3 e7 95  db 5d fc 9a
>| current Phase 1 IV:  bd c3 e7 95  db 5d fc 9a
>| computed Phase 2 IV:
>|   43 9c 26 92  3e 1f c7 07  a0 ee 9f 05  83 5a fd f2
>|   e1 f1 30 2e
>| received encrypted packet from 192.1.2.45:500
>| decrypting 96 bytes using algorithm OAKLEY_3DES_CBC
>| NSS: do_3des init start
>| NSS: do_3des init end
>| decrypted:
>|   01 00 00 18  e9 db 6c b7  fa 36 2a 5b  02 54 49 25
>|   69 ae fb 47  33 ca 75 34  0a 00 00 30  00 00 00 01
>|   00 00 00 01  00 00 00 24  00 03 04 01  e4 0a 5d f7
>|   00 00 00 18  00 03 00 00  80 04 00 02  80 01 00 01
>|   80 02 70 80  80 05 00 02  00 00 00 14  c8 ba 3b 83
>|   8a b9 e9 09  88 e8 a4 30  9b d0 64 54  00 00 00 00
>| next IV:  3a 6f 1b 28  d2 7c c1 c5
>| got payload 0x100(ISAKMP_NEXT_HASH) needed: 0x502 opt: 0x200030
>| ***parse ISAKMP Hash Payload:
>|    next payload type: ISAKMP_NEXT_SA
>|    length: 24
>| got payload 0x2(ISAKMP_NEXT_SA) needed: 0x402 opt: 0x200030
>| ***parse ISAKMP Security Association Payload:
>|    next payload type: ISAKMP_NEXT_NONCE
>|    length: 48
>|    DOI: ISAKMP_DOI_IPSEC
>| got payload 0x400(ISAKMP_NEXT_NONCE) needed: 0x400 opt: 0x200030
>| ***parse ISAKMP Nonce Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 20
>| removing 4 bytes of padding
>| HASH(1) computed:
>|   e9 db 6c b7  fa 36 2a 5b  02 54 49 25  69 ae fb 47
>|   33 ca 75 34
>"v4" #5: the peer proposed: 192.1.2.23/32:0/0 -> 192.1.2.45/32:0/0
>| find_client_connection starting with v4
>|   looking for 192.1.2.23/32:0/0 -> 192.1.2.45/32:0/0
>|   concrete checking against sr#0 192.1.2.23/32 -> 192.1.2.45/32
>| client wildcard: no  port wildcard: no  virtual: no
>| duplicating state object #5
>| creating state object #6 at 0x2b49aca3f390
>| processing connection v4
>| ICOOKIE:  f4 00 6c 29  85 9c 6f 95
>| RCOOKIE:  94 4a f0 cc  d0 a3 ed 33
>| state hash entry 9
>| inserting state object #6 on chain 9
>| inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #6
>| event added at head of queue
>| ****parse IPsec DOI SIT:
>|    IPsec DOI SIT: SIT_IDENTITY_ONLY
>| ****parse ISAKMP Proposal Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 36
>|    proposal number: 0
>|    protocol ID: PROTO_IPSEC_ESP
>|    SPI size: 4
>|    number of transforms: 1
>| parsing 4 raw bytes of ISAKMP Proposal Payload into SPI
>| SPI  e4 0a 5d f7
>| *****parse ISAKMP Transform Payload (ESP):
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 24
>|    transform number: 0
>|    transform ID: ESP_3DES
>| ******parse ISAKMP IPsec DOI attribute:
>|    af+type: ENCAPSULATION_MODE
>|    length/value: 2
>|    [2 is ENCAPSULATION_MODE_TRANSPORT]
>| ******parse ISAKMP IPsec DOI attribute:
>|    af+type: SA_LIFE_TYPE
>|    length/value: 1
>| ******parse ISAKMP IPsec DOI attribute:
>|    af+type: SA_LIFE_DURATION
>|    length/value: 28800
>| ******parse ISAKMP IPsec DOI attribute:
>|    af+type: AUTH_ALGORITHM
>|    length/value: 2
>| kernel_alg_esp_enc_ok(3,0): alg_id=3, alg_ivlen=8, alg_minbits=192, alg_maxbits=192, res=0, ret=1
>| kernel_alg_esp_enc_keylen():alg_id=3, keylen=24
>| 0: w->pcw_dead: 0 w->pcw_work: 0 cnt: 1
>| asking helper 0 to do build_nonce op on seq: 7 (len=2776, pcw_work=1)
>| crypto helper write of request: cnt=2776<wlen=2776.  
>| deleting event for #6
>| inserting event EVENT_CRYPTO_FAILED, timeout in 300 seconds for #6
>| event added after event EVENT_PENDING_PHASE2
>| complete state transition with STF_SUSPEND
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 19 seconds for #2
>| next event EVENT_RETRANSMIT in 19 seconds for #2
>| helper 0 read 2768+4/2776 bytes fd: 10
>| helper 0 doing build_nonce op id: 7
>| Generated nonce:
>|   40 2c 1b 1e  ef f0 68 6e  ef 68 6b 49  70 78 14 d1
>| 
>| helper 0 has finished work (cnt now 1)
>| helper 0 replies to id: q#7
>| calling callback function 0x2b49ac6dfe40
>| quick inI1_outR1: calculated ke+nonce, calculating DH
>| processing connection v4
>| **emit ISAKMP Message:
>|    initiator cookie:
>|   f4 00 6c 29  85 9c 6f 95
>|    responder cookie:
>|   94 4a f0 cc  d0 a3 ed 33
>|    next payload type: ISAKMP_NEXT_HASH
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_QUICK
>|    flags: ISAKMP_FLAG_ENCRYPTION
>|    message ID:  c1 a7 d8 34
>| ***emit ISAKMP Hash Payload:
>|    next payload type: ISAKMP_NEXT_SA
>| emitting 20 zero bytes of HASH into ISAKMP Hash Payload
>| emitting length of ISAKMP Hash Payload: 24
>| ***emit ISAKMP Security Association Payload:
>|    next payload type: ISAKMP_NEXT_NONCE
>|    DOI: ISAKMP_DOI_IPSEC
>| ****parse IPsec DOI SIT:
>|    IPsec DOI SIT: SIT_IDENTITY_ONLY
>| ****parse ISAKMP Proposal Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 36
>|    proposal number: 0
>|    protocol ID: PROTO_IPSEC_ESP
>|    SPI size: 4
>|    number of transforms: 1
>| parsing 4 raw bytes of ISAKMP Proposal Payload into SPI
>| SPI  e4 0a 5d f7
>| *****parse ISAKMP Transform Payload (ESP):
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 24
>|    transform number: 0
>|    transform ID: ESP_3DES
>| ******parse ISAKMP IPsec DOI attribute:
>|    af+type: ENCAPSULATION_MODE
>|    length/value: 2
>|    [2 is ENCAPSULATION_MODE_TRANSPORT]
>| ******parse ISAKMP IPsec DOI attribute:
>|    af+type: SA_LIFE_TYPE
>|    length/value: 1
>| ******parse ISAKMP IPsec DOI attribute:
>|    af+type: SA_LIFE_DURATION
>|    length/value: 28800
>| ******parse ISAKMP IPsec DOI attribute:
>|    af+type: AUTH_ALGORITHM
>|    length/value: 2
>| kernel_alg_esp_enc_ok(3,0): alg_id=3, alg_ivlen=8, alg_minbits=192, alg_maxbits=192, res=0, ret=1
>| kernel_alg_esp_enc_keylen():alg_id=3, keylen=24
>| ****emit IPsec DOI SIT:
>|    IPsec DOI SIT: SIT_IDENTITY_ONLY
>| ****emit ISAKMP Proposal Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    proposal number: 0
>|    protocol ID: PROTO_IPSEC_ESP
>|    SPI size: 4
>|    number of transforms: 1
>| netlink_get_spi: allocated 0x4933375 for esp.0@192.1.2.23
>| emitting 4 raw bytes of SPI into ISAKMP Proposal Payload
>| SPI  04 93 33 75
>| *****emit ISAKMP Transform Payload (ESP):
>|    next payload type: ISAKMP_NEXT_NONE
>|    transform number: 0
>|    transform ID: ESP_3DES
>| emitting 16 raw bytes of attributes into ISAKMP Transform Payload (ESP)
>| attributes  80 04 00 02  80 01 00 01  80 02 70 80  80 05 00 02
>| emitting length of ISAKMP Transform Payload (ESP): 24
>| emitting length of ISAKMP Proposal Payload: 36
>| emitting length of ISAKMP Security Association Payload: 48
>"v4" #6: responding to Quick Mode proposal {msgid:34d8a7c1}
>"v4" #6:     us: 192.1.2.23<192.1.2.23>[+S=C]
>"v4" #6:   them: 192.1.2.45<192.1.2.45>[+S=C]
>| ***emit ISAKMP Nonce Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>| emitting 16 raw bytes of Nr into ISAKMP Nonce Payload
>| Nr  40 2c 1b 1e  ef f0 68 6e  ef 68 6b 49  70 78 14 d1
>| emitting length of ISAKMP Nonce Payload: 20
>| HASH(2) computed:
>|   0b ce 44 a3  71 b2 b5 52  d1 8c e7 38  80 52 fc fe
>|   15 00 11 20
>| compute_proto_keymat:needed_len (after ESP enc)=24
>| compute_proto_keymat:needed_len (after ESP auth)=44
>| ESP KEYMAT 
>|   KEYMAT computed:
>|   48 e2 f7 5b  d9 5a 4c bf  26 2f a6 79  df d2 0a 89
>|   91 ec 9c 49  8d 6f 33 e1  c8 a5 b0 91  90 39 54 4b
>|   f9 e6 10 f3  27 aa 34 e6  2f 11 28 3f
>|   Peer KEYMAT computed:
>|   6c 62 9e 08  c9 bb a4 f5  52 7d 6d ae  b4 a7 89 bc
>|   64 11 52 bd  b9 10 29 0f  49 f1 f2 c5  34 1f 1d 16
>|   8d 1a be 18  73 6e 84 39  01 92 f3 af
>| install_inbound_ipsec_sa() checking if we can route
>| route owner of "v4" erouted: self; eroute owner: self
>| could_route called for v4 (kind=CK_PERMANENT)
>|    routing is easy, or has resolvable near-conflict
>| checking if this is a replacement state
>|   st=0x2b49aca3f390 ost=0x2b49aca2aba0 st->serialno=#6 ost->serialno=#4 
>"v4" #6: keeping refhim=4294901761 during rekey
>| outgoing SA has refhim=4294901761
>| looking for alg with transid: 3 keylen: 0 auth: 2 
>| checking transid: 11 keylen: 0 auth: 1 
>| checking transid: 11 keylen: 0 auth: 2 
>| checking transid: 2 keylen: 8 auth: 0 
>| checking transid: 2 keylen: 8 auth: 1 
>| checking transid: 2 keylen: 8 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:  48 e2 f7 5b  d9 5a 4c bf  26 2f a6 79  df d2 0a 89
>| esp enckey:  91 ec 9c 49  8d 6f 33 e1
>| esp authkey:  c8 a5 b0 91  90 39 54 4b  f9 e6 10 f3  27 aa 34 e6
>| esp authkey:  2f 11 28 3f
>|   using old struct xfrm_algo for XFRM message
>| encrypting:
>|   01 00 00 18  0b ce 44 a3  71 b2 b5 52  d1 8c e7 38
>|   80 52 fc fe  15 00 11 20  0a 00 00 30  00 00 00 01
>|   00 00 00 01  00 00 00 24  00 03 04 01  04 93 33 75
>|   00 00 00 18  00 03 00 00  80 04 00 02  80 01 00 01
>|   80 02 70 80  80 05 00 02  00 00 00 14  40 2c 1b 1e
>|   ef f0 68 6e  ef 68 6b 49  70 78 14 d1
>| IV:
>|   3a 6f 1b 28  d2 7c c1 c5
>| unpadded size is: 92
>| emitting 4 zero bytes of encryption padding into ISAKMP Message
>| encrypting 96 using OAKLEY_3DES_CBC
>| NSS: do_3des init start
>| NSS: do_3des init end
>| next IV:  f7 9b 0d d6  5e 29 15 c8
>| emitting length of ISAKMP Message: 124
>| finished processing quick inI1
>| complete state transition with STF_OK
>"v4" #6: transition from state STATE_QUICK_R0 to state STATE_QUICK_R1
>| deleting event for #6
>| sending reply packet to 192.1.2.45:500 (from port 500)
>| sending 124 bytes for STATE_QUICK_R0 through eth1:500 to 192.1.2.45:500 (using #6)
>|   f4 00 6c 29  85 9c 6f 95  94 4a f0 cc  d0 a3 ed 33
>|   08 10 20 01  c1 a7 d8 34  00 00 00 7c  ee 50 d7 10
>|   7a 0d 4e 8c  60 28 71 9f  f0 95 6c 6c  47 27 d2 51
>|   b7 86 bd 37  23 82 fb d1  e1 ff 7e a1  84 c4 a1 0b
>|   c8 0e 5e 44  a4 e5 19 02  d1 3a 21 fb  48 c4 6d 3d
>|   82 e7 b4 71  ae 38 0b e5  bf 70 b1 f4  02 c6 84 b6
>|   7a 8e 61 ed  27 52 76 f7  e6 63 1d c3  8e 3d 8d cb
>|   df f3 39 02  f7 9b 0d d6  5e 29 15 c8
>| inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #6
>| event added at head of queue
>"v4" #6: STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2
>| modecfg pull: noquirk policy:push not-client
>| phase 1 is done, looking for phase 2 to unpend
>| * processed 1 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 10 seconds for #6
>| next event EVENT_RETRANSMIT in 10 seconds for #6
>| 
>| *received 52 bytes from 192.1.2.45:500 on eth1 (port=500)
>|   f4 00 6c 29  85 9c 6f 95  94 4a f0 cc  d0 a3 ed 33
>|   08 10 20 01  c1 a7 d8 34  00 00 00 34  8f 06 4d 77
>|   b9 35 d7 15  30 d8 bc b9  f6 06 14 2a  4a e3 a4 84
>|   78 f1 d8 df
>| **parse ISAKMP Message:
>|    initiator cookie:
>|   f4 00 6c 29  85 9c 6f 95
>|    responder cookie:
>|   94 4a f0 cc  d0 a3 ed 33
>|    next payload type: ISAKMP_NEXT_HASH
>|    ISAKMP version: ISAKMP Version 1.0 (rfc2407)
>|    exchange type: ISAKMP_XCHG_QUICK
>|    flags: ISAKMP_FLAG_ENCRYPTION
>|    message ID:  c1 a7 d8 34
>|    length: 52
>|  processing version=1.0 packet with exchange type=ISAKMP_XCHG_QUICK (32)
>| ICOOKIE:  f4 00 6c 29  85 9c 6f 95
>| RCOOKIE:  94 4a f0 cc  d0 a3 ed 33
>| state hash entry 9
>| v1 peer and cookies match on #6, provided msgid c1a7d834 vs c1a7d834
>| v1 state object #6 found, in STATE_QUICK_R1
>| processing connection v4
>| received encrypted packet from 192.1.2.45:500
>| decrypting 24 bytes using algorithm OAKLEY_3DES_CBC
>| NSS: do_3des init start
>| NSS: do_3des init end
>| decrypted:
>|   00 00 00 18  d8 e7 55 d7  10 52 b2 8e  f6 91 d0 f1
>|   0f cc 1a b5  57 1a 54 46
>| next IV:  4a e3 a4 84  78 f1 d8 df
>| got payload 0x100(ISAKMP_NEXT_HASH) needed: 0x100 opt: 0x0
>| ***parse ISAKMP Hash Payload:
>|    next payload type: ISAKMP_NEXT_NONE
>|    length: 24
>| HASH(3) computed:  d8 e7 55 d7  10 52 b2 8e  f6 91 d0 f1  0f cc 1a b5
>| HASH(3) computed:  57 1a 54 46
>| install_ipsec_sa() for #6: outbound only
>| route owner of "v4" erouted: self; eroute owner: self
>| could_route called for v4 (kind=CK_PERMANENT)
>| looking for alg with transid: 3 keylen: 0 auth: 2 
>| checking transid: 11 keylen: 0 auth: 1 
>| checking transid: 11 keylen: 0 auth: 2 
>| checking transid: 2 keylen: 8 auth: 0 
>| checking transid: 2 keylen: 8 auth: 1 
>| checking transid: 2 keylen: 8 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:  6c 62 9e 08  c9 bb a4 f5  52 7d 6d ae  b4 a7 89 bc
>| esp enckey:  64 11 52 bd  b9 10 29 0f
>| esp authkey:  49 f1 f2 c5  34 1f 1d 16  8d 1a be 18  73 6e 84 39
>| esp authkey:  01 92 f3 af
>|   using old struct xfrm_algo for XFRM message
>| set up outoing SA, ref=0/4294901761
>| sr for #6: erouted
>| route owner of "v4" erouted: self; eroute owner: self
>| route_and_eroute with c: v4 (next: none) ero:v4 esr:{(nil)} ro:v4 rosr:{(nil)} and state: 6
>| eroute_connection replace eroute 192.1.2.23/32:0 --0-> 192.1.2.45/32:0 => esp.e40a5df7@192.1.2.45 (raw_eroute)
>| raw_eroute result=1 
>| route_and_eroute: firewall_notified: true
>| route_and_eroute: instance "v4", setting eroute_owner {spd=0x2b49aca0a520,sr=0x2b49aca0a520} to #6 (was #4) (newest_ipsec_sa=#4)
>| inI2: instance v4[0], setting newest_ipsec_sa to #6 (was #4) (spd.eroute=#6)
>| complete state transition with STF_OK
>"v4" #6: transition from state STATE_QUICK_R1 to state STATE_QUICK_R2
>| deleting event for #6
>| inserting event EVENT_SA_REPLACE, timeout in 28530 seconds for #6
>| event added after event EVENT_SA_REPLACE for #3
>"v4" #6: STATE_QUICK_R2: IPsec SA established transport mode {ESP=>0xe40a5df7 <0x04933375 xfrm=3DES_0-HMAC_SHA1 NATOA=none NATD=none DPD=none}
>| modecfg pull: noquirk policy:push not-client
>| phase 1 is done, looking for phase 2 to unpend
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 19 seconds for #2
>| next event EVENT_RETRANSMIT in 19 seconds for #2
>| 
>| *received whack message
>| kernel_alg_esp_enc_ok(3,0): alg_id=3, alg_ivlen=8, alg_minbits=192, alg_maxbits=192, res=0, ret=1
>| kernel_alg_esp_enc_keylen():alg_id=3, keylen=24
>| kernel_alg_esp_auth_keylen(auth=2, sadb_aalg=3): a_keylen=20
>| kernel_alg_esp_enc_ok(3,0): alg_id=3, alg_ivlen=8, alg_minbits=192, alg_maxbits=192, res=0, ret=1
>| kernel_alg_esp_enc_keylen():alg_id=3, keylen=24
>| kernel_alg_esp_auth_keylen(auth=2, sadb_aalg=3): a_keylen=20
>| get esp.e40a5df7@192.1.2.45
>| get esp.4933375@192.1.2.23
>| get esp.ce07a636@192.1.2.45
>| get esp.e116bd19@192.1.2.23
>| get esp.27096f94@192.1.2.45
>| get esp.8a85863c@192.1.2.23
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 3 seconds for #2
>| next event EVENT_RETRANSMIT in 3 seconds for #2
>| 
>| next event EVENT_RETRANSMIT in 0 seconds for #2
>| *time to handle event
>| handling event EVENT_RETRANSMIT
>| event after this is EVENT_PENDING_DDNS in 30 seconds
>| processing connection v6
>| handling event EVENT_RETRANSMIT for 2001:db8:1:2::45 "v6" #2
>| sending 148 bytes for EVENT_RETRANSMIT through eth1:500 to 2001:db8:1:2::45:500 (using #2)
>|   7f 70 da 29  ca d1 bc bf  00 00 00 00  00 00 00 00
>|   01 10 02 00  00 00 00 00  00 00 00 94  0d 00 00 54
>|   00 00 00 01  00 00 00 01  00 00 00 48  00 01 00 02
>|   03 00 00 20  00 01 00 00  80 0b 00 01  80 0c 0e 10
>|   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 05
>|   00 00 00 20  01 01 00 00  80 0b 00 01  80 0c 0e 10
>|   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 02
>|   0d 00 00 10  4f 45 68 79  4c 64 41 43  65 63 66 61
>|   00 00 00 14  af ca d7 13  68 a1 f1 c9  6b 86 96 fc
>|   77 57 01 00
>| inserting event EVENT_RETRANSMIT, timeout in 40 seconds for #2
>| event added after event EVENT_PENDING_DDNS
>| next event EVENT_PENDING_DDNS in 30 seconds
>| 
>| *received kernel message
>| netlink_get: XFRM_MSG_ACQUIRE message
>| xfrm netlink msg len 364
>| xfrm:nlmsghdr= 16
>| xfrm:acquire= 280
>| xfrm:rtattr= 4
>| rtattr len= 68
>| xfrm: found XFRMA_TMPL
>| xfrm: did not found XFRMA_SEC_CTX, trying next one
>| xfrm: rta->len=68
>| xfrm: remaining=0 , rta->len = 28274
>| xfrm: not found anything, seems wierd
>| xfrm: not found sec ctx still, perhaps not a labeled ipsec connection
>| add bare shunt 0x2b49aca4b340 2001:db8:1:2::23/128:136 --58--> 2001:db8:1:2::45/128:0 => %hold 0    %acquire-netlink
>| received security label string: 
>initiate on demand from 2001:db8:1:2::23:136 to 2001:db8:1:2::45:0 proto=58 state: fos_start because: acquire
>| find_connection: looking for policy for connection: 2001:db8:1:2::23:58/136 -> 2001:db8:1:2::45:58/0
>| find_connection: conn "v6" has compatible peers: 2001:db8:1:2::23/128 -> 2001:db8:1:2::45/128 [pri: 67371018]
>| find_connection: comparing best "v6" [pri:67371018]{0x2b49aca0bb00} (child none) to "v6" [pri:67371018]{0x2b49aca0bb00} (child none)
>| find_connection: concluding with "v6" [pri:67371018]{0x2b49aca0bb00} kind=CK_PERMANENT
>| assign hold, routing was erouted HOLD, needs to be erouted HOLD
>| delete bare shunt: null pointer
>| Queuing pending Quick Mode with 2001:db8:1:2::45 "v6"
>| delete bare shunt 0x2b49aca4b340 2001:db8:1:2::23/128:136 --58--> 2001:db8:1:2::45/128:0 => %hold 0    %acquire-netlink
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_PENDING_DDNS in 20 seconds
>| next event EVENT_PENDING_DDNS in 20 seconds
>| 
>| next event EVENT_PENDING_DDNS in 0 seconds
>| *time to handle event
>| handling event EVENT_PENDING_DDNS
>| event after this is EVENT_RETRANSMIT in 10 seconds
>| inserting event EVENT_PENDING_DDNS, timeout in 60 seconds
>| event added after event EVENT_RETRANSMIT for #2
>| next event EVENT_RETRANSMIT in 10 seconds for #2
>| 
>| next event EVENT_RETRANSMIT in 0 seconds for #2
>| *time to handle event
>| handling event EVENT_RETRANSMIT
>| event after this is EVENT_PENDING_DDNS in 50 seconds
>| processing connection v6
>| handling event EVENT_RETRANSMIT for 2001:db8:1:2::45 "v6" #2
>| sending 148 bytes for EVENT_RETRANSMIT through eth1:500 to 2001:db8:1:2::45:500 (using #2)
>|   7f 70 da 29  ca d1 bc bf  00 00 00 00  00 00 00 00
>|   01 10 02 00  00 00 00 00  00 00 00 94  0d 00 00 54
>|   00 00 00 01  00 00 00 01  00 00 00 48  00 01 00 02
>|   03 00 00 20  00 01 00 00  80 0b 00 01  80 0c 0e 10
>|   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 05
>|   00 00 00 20  01 01 00 00  80 0b 00 01  80 0c 0e 10
>|   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 02
>|   0d 00 00 10  4f 45 68 79  4c 64 41 43  65 63 66 61
>|   00 00 00 14  af ca d7 13  68 a1 f1 c9  6b 86 96 fc
>|   77 57 01 00
>| inserting event EVENT_RETRANSMIT, timeout in 40 seconds for #2
>| event added at head of queue
>| next event EVENT_RETRANSMIT in 40 seconds for #2
>| 
>| *received kernel message
>| netlink_get: XFRM_MSG_ACQUIRE message
>| xfrm netlink msg len 364
>| xfrm:nlmsghdr= 16
>| xfrm:acquire= 280
>| xfrm:rtattr= 4
>| rtattr len= 68
>| xfrm: found XFRMA_TMPL
>| xfrm: did not found XFRMA_SEC_CTX, trying next one
>| xfrm: rta->len=68
>| xfrm: remaining=0 , rta->len = 28274
>| xfrm: not found anything, seems wierd
>| xfrm: not found sec ctx still, perhaps not a labeled ipsec connection
>| add bare shunt 0x2b49aca4b340 2001:db8:1:2::23/128:136 --58--> 2001:db8:1:2::45/128:0 => %hold 0    %acquire-netlink
>| received security label string: 
>initiate on demand from 2001:db8:1:2::23:136 to 2001:db8:1:2::45:0 proto=58 state: fos_start because: acquire
>| find_connection: looking for policy for connection: 2001:db8:1:2::23:58/136 -> 2001:db8:1:2::45:58/0
>| find_connection: conn "v6" has compatible peers: 2001:db8:1:2::23/128 -> 2001:db8:1:2::45/128 [pri: 67371018]
>| find_connection: comparing best "v6" [pri:67371018]{0x2b49aca0bb00} (child none) to "v6" [pri:67371018]{0x2b49aca0bb00} (child none)
>| find_connection: concluding with "v6" [pri:67371018]{0x2b49aca0bb00} kind=CK_PERMANENT
>| assign hold, routing was erouted HOLD, needs to be erouted HOLD
>| delete bare shunt: null pointer
>| Queuing pending Quick Mode with 2001:db8:1:2::45 "v6"
>| delete bare shunt 0x2b49aca4b340 2001:db8:1:2::23/128:136 --58--> 2001:db8:1:2::45/128:0 => %hold 0    %acquire-netlink
>| * processed 0 messages from cryptographic helpers 
>| next event EVENT_RETRANSMIT in 30 seconds for #2
>| next event EVENT_RETRANSMIT in 30 seconds for #2
>| 
>| next event EVENT_RETRANSMIT in 0 seconds for #2
>| *time to handle event
>| handling event EVENT_RETRANSMIT
>| event after this is EVENT_PENDING_DDNS in 10 seconds
>| processing connection v6
>| handling event EVENT_RETRANSMIT for 2001:db8:1:2::45 "v6" #2
>| sending 148 bytes for EVENT_RETRANSMIT through eth1:500 to 2001:db8:1:2::45:500 (using #2)
>|   7f 70 da 29  ca d1 bc bf  00 00 00 00  00 00 00 00
>|   01 10 02 00  00 00 00 00  00 00 00 94  0d 00 00 54
>|   00 00 00 01  00 00 00 01  00 00 00 48  00 01 00 02
>|   03 00 00 20  00 01 00 00  80 0b 00 01  80 0c 0e 10
>|   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 05
>|   00 00 00 20  01 01 00 00  80 0b 00 01  80 0c 0e 10
>|   80 01 00 05  80 02 00 02  80 03 00 01  80 04 00 02
>|   0d 00 00 10  4f 45 68 79  4c 64 41 43  65 63 66 61
>|   00 00 00 14  af ca d7 13  68 a1 f1 c9  6b 86 96 fc
>|   77 57 01 00
>| inserting event EVENT_RETRANSMIT, timeout in 40 seconds for #2
>| event added after event EVENT_PENDING_PHASE2
>| next event EVENT_PENDING_DDNS in 10 seconds

Actions: View

Attachments on bug 759073: 861646 | 861647