[Openswan Users] OpenSwan - Juniper IPSEC tunnel problem
Alex Petcu
alex.petcu at sipstatus.com
Wed Jun 3 06:22:37 EDT 2015
Hi,
I am trying to build an IPSEC tunnel with a vendor that is using Juniper.
I tried pretty much all I could find while googling about this, but wasn't able to make this work, so hope you guys can help...
I am running version 1:2.6.37-3 (downgraded from 1:2.6.37-3+deb7u1 but it made no difference).
Here is my config:
Ipsec.secrets file:
IP1 IP2: PSK "preshared key"
Ipsec.conf:
version 2.0 # conforms to second version of ipsec.conf specification
# basic configuration
config setup
plutodebug="all"
plutoopts="--perpeerlog"
dumpdir=/var/run/pluto/
nat_traversal=no
virtual_private=%v4:5.153.18.208/30,%v4:!10.0.0.0/8,%v4:!192.168.0.0/16,%v4:!172.16.0.0/12,%v4:!25.0.0.0/8,%v6:!fd00::/8,%v6:!fe80::/10
oe=off
protostack=netkey
plutostderrlog=/var/log/plutolog
conn verizon
authby=secret
auto=start
ike=3des-md5;modp1024!
phase2alg=3des-md5
keyexchange=ike
left=IP1
leftsubnet=net3/30
leftnexthop=IP1 default gw
pfs=yes
right=IP2
rightsubnet=net4/27
type=tunnel
aggrmode=no
I enabled full plutodebug, and here is the output:
adjusting ipsec.d to /etc/ipsec.d
Starting Pluto (Openswan Version 2.6.37-g955aaafb-dirty; Vendor ID OEfdpoplS^}i) pid:30116
LEAK_DETECTIVE support [disabled]
OCF support for IKE [disabled]
SAref support [disabled]: Protocol not available
SAbind support [disabled]: Protocol not available
NSS support [disabled]
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]
| opening /dev/urandom
using /dev/urandom as source of random entropy
| 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_AES_CBC: Ok (ret=0)
starting up 7 cryptographic helpers
started helper pid=30120 (fd:4)
started helper pid=30121 (fd:6)
started helper pid=30122 (fd:7)
| opening /dev/urandom
using /dev/urandom as source of random entropy
! helper 0 waiting on fd: 6
| opening /dev/urandom
using /dev/urandom as source of random entropy
started helper pid=30123 (fd:8)
! helper 1 waiting on fd: 7
started helper pid=30124 (fd:9)
| opening /dev/urandom
using /dev/urandom as source of random entropy
| opening /dev/urandom
using /dev/urandom as source of random entropy
started helper pid=30125 (fd:10)
! helper 3 waiting on fd: 9
! helper 2 waiting on fd: 8
| opening /dev/urandom
using /dev/urandom as source of random entropy
started helper pid=30126 (fd:11)
Using Linux 2.6 IPsec interface code on 3.2.0-4-amd64 (experimental code)
| process 30116 listening for PF_KEY_V2 on file descriptor 14
| finish_pfkey_msg: K_SADB_REGISTER message 1 for AH
| 02 07 00 02 02 00 00 00 01 00 00 00 a4 75 00 00
! helper 4 waiting on fd: 10
| opening /dev/urandom
using /dev/urandom as source of random entropy
! helper 5 waiting on fd: 11
| opening /dev/urandom
using /dev/urandom as source of random entropy
! helper 6 waiting on fd: 12
| 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 a4 75 00 00
| pfkey_get: K_SADB_REGISTER message 2
| alg_init():memset(0x7fd130998680, 0, 2016) memset(0x7fd130998e60, 0, 2048)
| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: sadb_msg_len=22 sadb_supported_len=72
| kernel_alg_add():satype=3, exttype=14, alg_id=251
| 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=6
| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[4], exttype=14, satype=3, alg_id=6, alg_ivlen=0, alg_minbits=384, alg_maxbits=384, res=0, ret=1
| kernel_alg_add():satype=3, exttype=14, alg_id=7
| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[5], exttype=14, satype=3, alg_id=7, alg_ivlen=0, alg_minbits=512, alg_maxbits=512, res=0, ret=1
| kernel_alg_add():satype=3, exttype=14, alg_id=8
| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[6], exttype=14, satype=3, alg_id=8, alg_ivlen=0, alg_minbits=160, alg_maxbits=160, res=0, ret=1
| kernel_alg_add():satype=3, exttype=14, alg_id=9
| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[7], exttype=14, satype=3, alg_id=9, alg_ivlen=0, alg_minbits=128, alg_maxbits=128, res=0, ret=1
| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: sadb_msg_len=22 sadb_supported_len=88
| kernel_alg_add():satype=3, exttype=15, alg_id=11
| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[8], exttype=15, satype=3, alg_id=11, alg_ivlen=0, alg_minbits=0, alg_maxbits=0, res=0, ret=1
| kernel_alg_add():satype=3, exttype=15, alg_id=2
| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[9], exttype=15, satype=3, alg_id=2, alg_ivlen=8, alg_minbits=64, alg_maxbits=64, res=0, ret=1
| kernel_alg_add():satype=3, exttype=15, alg_id=3
| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[10], exttype=15, satype=3, alg_id=3, alg_ivlen=8, alg_minbits=192, alg_maxbits=192, res=0, ret=1
| kernel_alg_add():satype=3, exttype=15, alg_id=6
| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[11], exttype=15, satype=3, alg_id=6, alg_ivlen=8, alg_minbits=40, alg_maxbits=128, res=0, ret=1
| kernel_alg_add():satype=3, exttype=15, alg_id=7
| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[12], exttype=15, satype=3, alg_id=7, alg_ivlen=8, alg_minbits=40, alg_maxbits=448, res=0, ret=1
| kernel_alg_add():satype=3, exttype=15, alg_id=12
| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[13], exttype=15, satype=3, alg_id=12, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
| kernel_alg_add():satype=3, exttype=15, alg_id=252
| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[14], exttype=15, satype=3, alg_id=252, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
| kernel_alg_add():satype=3, exttype=15, alg_id=22
| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[15], exttype=15, satype=3, alg_id=22, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
| kernel_alg_add():satype=3, exttype=15, alg_id=253
| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[16], exttype=15, satype=3, alg_id=253, alg_ivlen=8, alg_minbits=128, alg_maxbits=256, res=0, ret=1
| kernel_alg_add():satype=3, exttype=15, alg_id=13
| kernel_alg_register_pfkey(): SADB_SATYPE_ESP: alg[17], exttype=15, satype=3, alg_id=13, alg_ivlen=8, alg_minbits=160, alg_maxbits=288, res=0, ret=1
| kernel_alg_add():satype=3, exttype=15, alg_id=18
| 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 a4 75 00 00
| pfkey_get: K_SADB_REGISTER message 3
| IPCOMP registered with kernel.
Changed path to directory '/etc/ipsec.d/cacerts'
Changed path to directory '/etc/ipsec.d/aacerts'
Changed path to directory '/etc/ipsec.d/ocspcerts'
Changing to directory '/etc/ipsec.d/crls'
Warning: empty directory
| inserting event EVENT_LOG_DAILY, timeout in 51292 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=md5eklen=0 aklen=0
| enum_search_prefix () calling enum_search(0x7fd13097a900, "OAKLEY_3DES")
| enum_search_ppfixi () calling enum_search(0x7fd13097a900, "OAKLEY_3DES_CBC")
| parser_alg_info_add() ealg_getbyname("3des")=5
| enum_search_prefix () calling enum_search(0x7fd13097a8e0, "OAKLEY_MD5")
| parser_alg_info_add() aalg_getbyname("md5")=1
| enum_search_prefix () calling enum_search(0x7fd13097a8a0, "OAKLEY_GROUP_MODP1024")
| parser_alg_info_add() modp_getbyname("modp1024")=2
| __alg_info_ike_add() ealg=5 aalg=1 modp_id=2, cnt=1
| Added new connection verizon with policy PSK+ENCRYPT+TUNNEL+PFS+IKEv2ALLOW+SAREFTRACK
| from whack: got --esp=3des-md5
| alg_info_parse_str() ealg_buf=3des aalg_buf=md5eklen=0 aklen=0
| enum_search_prefix () calling enum_search(0x7fd13097aa20, "ESP_3DES")
| parser_alg_info_add() ealg_getbyname("3des")=3
| enum_search_prefix () calling enum_search(0x7fd1309750a0, "AUTH_ALGORITHM_HMAC_MD5")
| parser_alg_info_add() aalg_getbyname("md5")=1
| __alg_info_esp_add() ealg=3 aalg=1 cnt=1
| esp string values: 3DES(3)_000-MD5(1)_000; flags=-strict
| ike (phase1) algorihtm values: 3DES_CBC(5)_000-MD5(1)_000-MODP1024(2); flags=strict
| counting wild cards for IP1 is 0
| counting wild cards for IP2 is 0
| alg_info_addref() alg_info->ref_cnt=1
| alg_info_addref() alg_info->ref_cnt=1
added connection description "verizon"
| NET3/30===IP1<IP1>[+S=C]---37.58.73.97...IP2<IP2>[+S=C]===NET4/27
| ike_life: 3600s; ipsec_life: 28800s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0; policy: PSK+ENCRYPT+TUNNEL+PFS+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 bond0 with address 10.70.222.12
| found bond1 with address IP1
| found bond1 with address 5.153.31.10
| found bond2 with address 5.153.31.14
| found bond1:0 with address 5.153.31.14
| found bond1.0 with address 5.153.31.14
adding interface bond2/bond2 5.153.31.14:500
adding interface bond1/bond1 5.153.31.10:500
adding interface bond1/bond1 IP1:500
adding interface bond0/bond0 10.70.222.12:500
adding interface lo/lo 127.0.0.1:500
| found bond1 with address 2a03:8180:1001:00f0:0225:90ff:fe7c:cf5d
| found lo with address 0000:0000:0000:0000:0000:0000:0000:0001
adding interface lo/lo ::1:500
adding interface bond1/bond1 2a03:8180:1001:f0:225:90ff:fe7c:cf5d:500
| connect_to_host_pair: IP1:500 IP2:500 -> hp:none
loading secrets from "/etc/ipsec.secrets"
| id type added to secret(0x7fd131f72e70) PPK_PSK: IP1
| id type added to secret(0x7fd131f72e70) PPK_PSK: IP2
| Processing PSK at line 2: passed
| id type added to secret(0x7fd131f72fe0) PPK_PSK: IP1
| id type added to secret(0x7fd131f72fe0) PPK_PSK: 159.8.149.69
| Processing PSK at line 3: 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 verizon
| route owner of "verizon" unrouted: NULL; eroute owner: NULL
| could_route called for verizon (kind=CK_PERMANENT)
| route owner of "verizon" unrouted: NULL; eroute owner: NULL
| route_and_eroute with c: verizon (next: none) ero:null esr:{(nil)} ro:null rosr:{(nil)} and state: 0
| request to add a prospective erouted policy with netkey kernel --- experimental
| satype(0) is not used in netlink_raw_eroute.
| route_and_eroute: firewall_notified: true
| command executing prepare-client
| executing prepare-client: 2>&1 PLUTO_VERB='prepare-client' PLUTO_VERSION='2.0' PLUTO_CONNECTION='verizon' PLUTO_INTERFACE='bond1' PLUTO_NEXT_HOP='37.58.73.97' PLUTO_ME='IP1' PLUTO_MY_ID='IP1' PLUTO_MY_CLIENT='NET3/30' PLUTO_MY_CLIENT_NET='NET3' PLUTO_MY_CLIENT_MASK='255.255.255.252' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='IP2' PLUTO_PEER_ID='IP2' PLUTO_PEER_CLIENT='NET4/27' PLUTO_PEER_CLIENT_NET='NET4' PLUTO_PEER_CLIENT_MASK='255.255.255.224' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey' PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+IKEv2ALLOW+SAREFTRACK' PLUTO_CONN_ADDRFAMILY='ipv4' PLUTO_CISCO_DNS_INFO='' PLUTO_CISCO_DOMAIN_INFO='' PLUTO_PEER_BANNER='' PLUTO_NM_CONFIGURED='0' ipsec _updown
| popen(): cmd is 788 chars long
| cmd( 0):2>&1 PLUTO_VERB='prepare-client' PLUTO_VERSION='2.0' PLUTO_CONNECTION='verizon' :
| cmd( 80):PLUTO_INTERFACE='bond1' PLUTO_NEXT_HOP='37.58.73.97' PLUTO_ME='IP1' PLUT:
| cmd( 160):O_MY_ID='IP1' PLUTO_MY_CLIENT='NET3/30' PLUTO_MY_CLIENT_NET='5.1:
| cmd( 240):53.18.208' PLUTO_MY_CLIENT_MASK='255.255.255.252' PLUTO_MY_PORT='0' PLUTO_MY_PRO:
| cmd( 320):TOCOL='0' PLUTO_PEER='IP2' PLUTO_PEER_ID='IP2' PLUTO_PEER_CL:
| cmd( 400):IENT='NET4/27' PLUTO_PEER_CLIENT_NET='NET4' PLUTO_PEER_CLIENT_MASK:
| cmd( 480):='255.255.255.224' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' :
| cmd( 560):PLUTO_STACK='netkey' PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+IKEv2ALLOW+SARE:
| cmd( 640):FTRACK' PLUTO_CONN_ADDRFAMILY='ipv4' PLUTO_CISCO_DNS_INFO='' PLUTO_CISCO_DOMAI:
| cmd( 720):N_INFO='' PLUTO_PEER_BANNER='' PLUTO_NM_CONFIGURED='0' ipsec _updown:
| command executing route-client
| executing route-client: 2>&1 PLUTO_VERB='route-client' PLUTO_VERSION='2.0' PLUTO_CONNECTION='verizon' PLUTO_INTERFACE='bond1' PLUTO_NEXT_HOP='37.58.73.97' PLUTO_ME='IP1' PLUTO_MY_ID='IP1' PLUTO_MY_CLIENT='NET3/30' PLUTO_MY_CLIENT_NET='NET3' PLUTO_MY_CLIENT_MASK='255.255.255.252' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_PEER='IP2' PLUTO_PEER_ID='IP2' PLUTO_PEER_CLIENT='NET4/27' PLUTO_PEER_CLIENT_NET='NET4' PLUTO_PEER_CLIENT_MASK='255.255.255.224' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='netkey' PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+IKEv2ALLOW+SAREFTRACK' PLUTO_CONN_ADDRFAMILY='ipv4' PLUTO_CISCO_DNS_INFO='' PLUTO_CISCO_DOMAIN_INFO='' PLUTO_PEER_BANNER='' PLUTO_NM_CONFIGURED='0' ipsec _updown
| popen(): cmd is 786 chars long
| cmd( 0):2>&1 PLUTO_VERB='route-client' PLUTO_VERSION='2.0' PLUTO_CONNECTION='verizon' PL:
| cmd( 80):UTO_INTERFACE='bond1' PLUTO_NEXT_HOP='37.58.73.97' PLUTO_ME='IP1' PLUTO_:
| cmd( 160):MY_ID='IP1' PLUTO_MY_CLIENT='NET3/30' PLUTO_MY_CLIENT_NET='5.153:
| cmd( 240):.18.208' PLUTO_MY_CLIENT_MASK='255.255.255.252' PLUTO_MY_PORT='0' PLUTO_MY_PROTO:
| cmd( 320):COL='0' PLUTO_PEER='IP2' PLUTO_PEER_ID='IP2' PLUTO_PEER_CLIE:
| cmd( 400):NT='NET4/27' PLUTO_PEER_CLIENT_NET='NET4' PLUTO_PEER_CLIENT_MASK=':
| cmd( 480):255.255.255.224' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PL:
| cmd( 560):UTO_STACK='netkey' PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+IKEv2ALLOW+SAREFT:
| cmd( 640):RACK' PLUTO_CONN_ADDRFAMILY='ipv4' PLUTO_CISCO_DNS_INFO='' PLUTO_CISCO_DOMAIN_:
| cmd( 720):INFO='' PLUTO_PEER_BANNER='' PLUTO_NM_CONFIGURED='0' 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 whack message
| processing connection verizon
| kernel_alg_db_new() initial trans_cnt=128
| kernel_alg_db_new() will return p_new->protoid=3, p_new->trans_cnt=1
| kernel_alg_db_new() trans[0]: transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=1
| returning new proposal from esp_info
| creating state object #1 at 0x7fd131f73390
| processing connection verizon
| ICOOKIE: c6 e6 3b df 9c 8a 6c 3d
| RCOOKIE: 00 00 00 00 00 00 00 00
| state hash entry 27
| inserting state object #1 on chain 27
| inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #1
| event added at head of queue
| processing connection verizon
| Queuing pending Quick Mode with IP2 "verizon"
"verizon" #1: initiating Main Mode
| **emit ISAKMP Message:
| initiator cookie:
| c6 e6 3b df 9c 8a 6c 3d
| 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: 1
| ****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
| ******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: 1
| [1 is OAKLEY_MD5]
| ******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: 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 66 64 70 6f 70 6c 53 5e 7d 69
| 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: 116
| sending 116 bytes for main_outI1 through bond1:500 to IP2:500 (using #1)
| c6 e6 3b df 9c 8a 6c 3d 00 00 00 00 00 00 00 00
| 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 01 80 03 00 01 80 04 00 02
| 0d 00 00 10 4f 45 66 64 70 6f 70 6c 53 5e 7d 69
| 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
| * 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 156 bytes from IP2:500 on bond1 (port=500)
| c6 e6 3b df 9c 8a 6c 3d 19 cd c7 2d a4 f9 12 f1
| 01 10 02 00 00 00 00 00 00 00 00 9c 0d 00 00 34
| 00 00 00 01 00 00 00 01 00 00 00 28 01 01 00 01
| 00 00 00 20 01 01 00 00 80 01 00 05 80 02 00 01
| 80 04 00 02 80 03 00 01 80 0b 00 01 80 0c 0e 10
| 0d 00 00 20 ef 6f e2 2f f0 19 cb a6 f5 b8 3e d2
| 63 c9 fc e0 db 7f 5b 49 00 00 00 0a 00 00 06 1e
| 0d 00 00 14 af ca d7 13 68 a1 f1 c9 6b 86 96 fc
| 77 57 01 00 00 00 00 18 48 65 61 72 74 42 65 61
| 74 5f 4e 6f 74 69 66 79 38 6b 01 00
| **parse ISAKMP Message:
| initiator cookie:
| c6 e6 3b df 9c 8a 6c 3d
| responder cookie:
| 19 cd c7 2d a4 f9 12 f1
| 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: 156
| processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
| ICOOKIE: c6 e6 3b df 9c 8a 6c 3d
| RCOOKIE: 19 cd c7 2d a4 f9 12 f1
| state hash entry 9
| v1 state object not found
| ICOOKIE: c6 e6 3b df 9c 8a 6c 3d
| RCOOKIE: 00 00 00 00 00 00 00 00
| state hash entry 27
| v1 peer and cookies match on #1, provided msgid 00000000 vs 00000000
| v1 state object #1 found, in STATE_MAIN_I1
| processing connection verizon
| 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: 32
| got payload 0x2000(ISAKMP_NEXT_VID) needed: 0x0 opt: 0x2080
| ***parse ISAKMP Vendor ID Payload:
| next payload type: ISAKMP_NEXT_VID
| length: 20
| got payload 0x2000(ISAKMP_NEXT_VID) needed: 0x0 opt: 0x2080
| ***parse ISAKMP Vendor ID Payload:
| next payload type: ISAKMP_NEXT_NONE
| length: 24
"verizon" #1: ignoring unknown Vendor ID payload [ef6fe22ff019cba6f5b83ed263c9fce0db7f5b490000000a0000061e]
"verizon" #1: received Vendor ID payload [Dead Peer Detection]
"verizon" #1: ignoring Vendor ID payload [HeartBeat Notify 386b0100]
| ****parse IPsec DOI SIT:
| IPsec DOI SIT: SIT_IDENTITY_ONLY
| ****parse ISAKMP Proposal Payload:
| next payload type: ISAKMP_NEXT_NONE
| length: 40
| proposal number: 1
| 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: 1
| transform ID: KEY_IKE
| ******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: 1
| [1 is OAKLEY_MD5]
| ******parse ISAKMP Oakley attribute:
| af+type: OAKLEY_GROUP_DESCRIPTION
| length/value: 2
| [2 is OAKLEY_GROUP_MODP1024]
| ******parse ISAKMP Oakley attribute:
| af+type: OAKLEY_AUTHENTICATION_METHOD
| length/value: 1
| [1 is OAKLEY_PRESHARED_KEY]
| started looking for secret for IP1->IP2 of kind PPK_PSK
| actually looking for secret for IP1->IP2 of kind PPK_PSK
| line 2: key type PPK_PSK(IP1) to type PPK_PSK
| 1: compared key 159.8.149.69 to IP1 / IP2 -> 0
| 2: compared key IP1 to IP1 / IP2 -> 8
| line 2: match=8
| line 1: key type PPK_PSK(IP1) to type PPK_PSK
| 1: compared key IP2 to IP1 / IP2 -> 4
| 2: compared key IP1 to IP1 / IP2 -> 12
| line 1: match=12
| best_match 0>12 best=0x7fd131f72e70 (line=1)
| concluding with best_match=12 best=0x7fd131f72e70 (lineno=1)
| ******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
| Oakley Transform 1 accepted
| sender checking NAT-t: 0 and 0
| 1: w->pcw_dead: 0 w->pcw_work: 0 cnt: 7
| asking helper 1 to do build_kenonce op on seq: 1 (len=2752, pcw_work=1)
| crypto helper write of request: cnt=2752<wlen=2752.
| 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
! helper 1 read 2744+4/2752 bytesfd: 7
! helper 1 doing build_kenonce op id: 1
! Local DH secret:
! 0d 12 e9 36 36 29 32 e6 62 c6 af be 7b b6 b0 15
! 19 36 99 d5 42 13 6b 56 c0 91 ed 37 0d f8 09 5a
! Public DH value sent:
! f8 c5 e3 5f f1 28 06 ad 6e 31 e0 47 cf ff 1c 7e
! 70 d2 29 cd ca bc b9 9b 81 6c d2 96 c4 a0 f7 50
! 74 6b 1b 37 98 bb 61 b8 05 ff 6d a9 d3 51 e4 f0
! ee 33 c0 ce 3a 21 90 82 23 de a8 52 50 56 1c ce
! 87 03 b6 be 57 0e 44 da cd 8a 42 79 3b 27 bc a0
! 7b 87 e3 61 0b a1 b7 bc 81 98 c6 81 44 0f bc 42
! df 5f 25 54 54 e7 b5 3f d7 ac 87 ad 23 ae 4f d5
! 59 fb f7 5c e9 2b 6d 39 e3 b2 38 09 cc 9a a3 4c
! Generated nonce:
! f3 04 d0 54 fe 9e 9b 83 37 23 0e 02 bf 88 27 40
|
| helper 1 has finished work (cnt now 1)
| helper 1 replies to id: q#1
| calling callback function 0x7fd1306c9960
| main inR1_outI2: calculated ke+nonce, sending I2
| processing connection verizon
| **emit ISAKMP Message:
| initiator cookie:
| c6 e6 3b df 9c 8a 6c 3d
| responder cookie:
| 19 cd c7 2d a4 f9 12 f1
| 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
| ***emit ISAKMP Key Exchange Payload:
| next payload type: ISAKMP_NEXT_NONCE
| emitting 128 raw bytes of keyex value into ISAKMP Key Exchange Payload
| keyex value f8 c5 e3 5f f1 28 06 ad 6e 31 e0 47 cf ff 1c 7e
| keyex value 70 d2 29 cd ca bc b9 9b 81 6c d2 96 c4 a0 f7 50
| keyex value 74 6b 1b 37 98 bb 61 b8 05 ff 6d a9 d3 51 e4 f0
| keyex value ee 33 c0 ce 3a 21 90 82 23 de a8 52 50 56 1c ce
| keyex value 87 03 b6 be 57 0e 44 da cd 8a 42 79 3b 27 bc a0
| keyex value 7b 87 e3 61 0b a1 b7 bc 81 98 c6 81 44 0f bc 42
| keyex value df 5f 25 54 54 e7 b5 3f d7 ac 87 ad 23 ae 4f d5
| keyex value 59 fb f7 5c e9 2b 6d 39 e3 b2 38 09 cc 9a a3 4c
| emitting length of ISAKMP Key Exchange Payload: 132
| ***emit ISAKMP Nonce Payload:
| next payload type: ISAKMP_NEXT_NONE
| emitting 16 raw bytes of Ni into ISAKMP Nonce Payload
| Ni f3 04 d0 54 fe 9e 9b 83 37 23 0e 02 bf 88 27 40
| emitting length of ISAKMP Nonce Payload: 20
| emitting length of ISAKMP Message: 180
| ICOOKIE: c6 e6 3b df 9c 8a 6c 3d
| RCOOKIE: 00 00 00 00 00 00 00 00
| state hash entry 27
| ICOOKIE: c6 e6 3b df 9c 8a 6c 3d
| RCOOKIE: 19 cd c7 2d a4 f9 12 f1
| state hash entry 9
| inserting state object #1 on chain 9
| complete state transition with STF_OK
"verizon" #1: transition from state STATE_MAIN_I1 to state STATE_MAIN_I2
| deleting event for #1
| sending reply packet to IP2:500 (from port 500)
| sending 180 bytes for STATE_MAIN_I1 through bond1:500 to IP2:500 (using #1)
| c6 e6 3b df 9c 8a 6c 3d 19 cd c7 2d a4 f9 12 f1
| 04 10 02 00 00 00 00 00 00 00 00 b4 0a 00 00 84
| f8 c5 e3 5f f1 28 06 ad 6e 31 e0 47 cf ff 1c 7e
| 70 d2 29 cd ca bc b9 9b 81 6c d2 96 c4 a0 f7 50
| 74 6b 1b 37 98 bb 61 b8 05 ff 6d a9 d3 51 e4 f0
| ee 33 c0 ce 3a 21 90 82 23 de a8 52 50 56 1c ce
| 87 03 b6 be 57 0e 44 da cd 8a 42 79 3b 27 bc a0
| 7b 87 e3 61 0b a1 b7 bc 81 98 c6 81 44 0f bc 42
| df 5f 25 54 54 e7 b5 3f d7 ac 87 ad 23 ae 4f d5
| 59 fb f7 5c e9 2b 6d 39 e3 b2 38 09 cc 9a a3 4c
| 00 00 00 14 f3 04 d0 54 fe 9e 9b 83 37 23 0e 02
| bf 88 27 40
| inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
| event added at head of queue
"verizon" #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 196 bytes from IP2:500 on bond1 (port=500)
| c6 e6 3b df 9c 8a 6c 3d 19 cd c7 2d a4 f9 12 f1
| 04 10 02 00 00 00 00 00 00 00 00 c4 0a 00 00 84
| 10 da 54 6e 56 db 85 7c c2 26 5f f8 a2 84 3b 46
| 22 40 f8 24 46 ec 32 f4 5e 9b 2d 17 d4 a6 02 a0
| 9e 47 cc 33 34 90 74 f6 0f 9f 6e 05 5c e3 d6 64
| 64 70 5b 50 3b a3 e8 2c 2a 99 78 76 85 c6 91 69
| ec 5b 19 af 9e a9 d8 24 6c d7 06 16 d7 84 8e c4
| 12 c8 6b ef 3e da a7 2d 85 2f 54 70 d4 5f 59 0d
| 91 1e 02 63 57 63 03 5d 1f 9a a2 bb d5 3d 32 fb
| c4 93 12 56 09 18 54 ad 6d 04 49 3a d9 48 f9 0e
| 00 00 00 24 89 35 b9 d5 3f dc 76 1d 63 0f 0e ac
| cf 7a 1d b0 2d e7 19 98 44 d5 41 13 ab 4f e8 d7
| 7b 98 ce f3
| **parse ISAKMP Message:
| initiator cookie:
| c6 e6 3b df 9c 8a 6c 3d
| responder cookie:
| 19 cd c7 2d a4 f9 12 f1
| 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: 196
| processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
| ICOOKIE: c6 e6 3b df 9c 8a 6c 3d
| RCOOKIE: 19 cd c7 2d a4 f9 12 f1
| state hash entry 9
| v1 peer and cookies match on #1, provided msgid 00000000 vs 00000000
| v1 state object #1 found, in STATE_MAIN_I2
| processing connection verizon
| got payload 0x10(ISAKMP_NEXT_KE) needed: 0x410 opt: 0x102080
| ***parse ISAKMP Key Exchange Payload:
| next payload type: ISAKMP_NEXT_NONCE
| length: 132
| got payload 0x400(ISAKMP_NEXT_NONCE) needed: 0x400 opt: 0x102080
| ***parse ISAKMP Nonce Payload:
| next payload type: ISAKMP_NEXT_NONE
| length: 36
| **emit ISAKMP Message:
| initiator cookie:
| c6 e6 3b df 9c 8a 6c 3d
| responder cookie:
| 19 cd c7 2d a4 f9 12 f1
| 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:
| 10 da 54 6e 56 db 85 7c c2 26 5f f8 a2 84 3b 46
| 22 40 f8 24 46 ec 32 f4 5e 9b 2d 17 d4 a6 02 a0
| 9e 47 cc 33 34 90 74 f6 0f 9f 6e 05 5c e3 d6 64
| 64 70 5b 50 3b a3 e8 2c 2a 99 78 76 85 c6 91 69
| ec 5b 19 af 9e a9 d8 24 6c d7 06 16 d7 84 8e c4
| 12 c8 6b ef 3e da a7 2d 85 2f 54 70 d4 5f 59 0d
| 91 1e 02 63 57 63 03 5d 1f 9a a2 bb d5 3d 32 fb
| c4 93 12 56 09 18 54 ad 6d 04 49 3a d9 48 f9 0e
| started looking for secret for IP1->IP2 of kind PPK_PSK
| actually looking for secret for IP1->IP2 of kind PPK_PSK
| line 2: key type PPK_PSK(IP1) to type PPK_PSK
| 1: compared key 159.8.149.69 to IP1 / IP2 -> 0
| 2: compared key IP1 to IP1 / IP2 -> 8
| line 2: match=8
| line 1: key type PPK_PSK(IP1) to type PPK_PSK
| 1: compared key IP2 to IP1 / IP2 -> 4
| 2: compared key IP1 to IP1 / IP2 -> 12
| line 1: match=12
| best_match 0>12 best=0x7fd131f72e70 (line=1)
| concluding with best_match=12 best=0x7fd131f72e70 (lineno=1)
| parent1 type: 7 group: 2 len: 2752
| 2: w->pcw_dead: 0 w->pcw_work: 0 cnt: 7
| asking helper 2 to do compute dh+iv op on seq: 2 (len=2752, pcw_work=1)
| crypto helper write of request: cnt=2752<wlen=2752.
| 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_PENDING_DDNS in 60 seconds
| next event EVENT_PENDING_DDNS in 60 seconds
! helper 2 read 2744+4/2752 bytesfd: 8
! helper 2 doing compute dh+iv op id: 2
! peer's g: 10 da 54 6e 56 db 85 7c c2 26 5f f8 a2 84 3b 46
! peer's g: 22 40 f8 24 46 ec 32 f4 5e 9b 2d 17 d4 a6 02 a0
! peer's g: 9e 47 cc 33 34 90 74 f6 0f 9f 6e 05 5c e3 d6 64
! peer's g: 64 70 5b 50 3b a3 e8 2c 2a 99 78 76 85 c6 91 69
! peer's g: ec 5b 19 af 9e a9 d8 24 6c d7 06 16 d7 84 8e c4
! peer's g: 12 c8 6b ef 3e da a7 2d 85 2f 54 70 d4 5f 59 0d
! peer's g: 91 1e 02 63 57 63 03 5d 1f 9a a2 bb d5 3d 32 fb
! peer's g: c4 93 12 56 09 18 54 ad 6d 04 49 3a d9 48 f9 0e
! long term secret: 0d 12 e9 36 36 29 32 e6 62 c6 af be 7b b6 b0 15
! long term secret: 19 36 99 d5 42 13 6b 56 c0 91 ed 37 0d f8 09 5a
! calc_dh_shared(): time elapsed (OAKLEY_GROUP_MODP1024): 196 usec
! DH shared-secret:
! 4f cc 32 02 86 1d 3f 3d 52 17 ac 01 cf ce ea 7d
! c4 1d fd d0 db 33 d9 b5 2c c4 e4 31 3e 8a 9e 1c
! a2 50 51 53 3e 8d 3e 59 57 6a 61 dc 67 f9 32 b5
! 80 c7 6d 67 83 af ac c0 57 96 94 9b 16 7e 71 87
! ac 8b b6 b7 84 4c aa a8 38 7f 73 70 a4 c6 05 54
! 70 18 ae 38 3a 07 1e 0a d3 fc a5 c9 31 f7 30 4b
! 9b 98 89 cc 3a eb a5 64 e7 d9 3f 0d e5 82 74 da
! 06 e8 61 93 de 5e 59 ed 3f a7 13 2f 22 27 3b 94
! Skey inputs (PSK+NI+NR)
! ni: f3 04 d0 54 fe 9e 9b 83 37 23 0e 02 bf 88 27 40
! nr: 89 35 b9 d5 3f dc 76 1d 63 0f 0e ac cf 7a 1d b0
! nr: 2d e7 19 98 44 d5 41 13 ab 4f e8 d7 7b 98 ce f3
! keyid: 71 4a c6 a9 8c db c2 0a 26 47 e9 cf 18 37 f2 5d
! NSS: end of key computation
! DH_i: f8 c5 e3 5f f1 28 06 ad 6e 31 e0 47 cf ff 1c 7e
! DH_i: 70 d2 29 cd ca bc b9 9b 81 6c d2 96 c4 a0 f7 50
! DH_i: 74 6b 1b 37 98 bb 61 b8 05 ff 6d a9 d3 51 e4 f0
! DH_i: ee 33 c0 ce 3a 21 90 82 23 de a8 52 50 56 1c ce
! DH_i: 87 03 b6 be 57 0e 44 da cd 8a 42 79 3b 27 bc a0
! DH_i: 7b 87 e3 61 0b a1 b7 bc 81 98 c6 81 44 0f bc 42
! DH_i: df 5f 25 54 54 e7 b5 3f d7 ac 87 ad 23 ae 4f d5
! DH_i: 59 fb f7 5c e9 2b 6d 39 e3 b2 38 09 cc 9a a3 4c
! DH_r: 10 da 54 6e 56 db 85 7c c2 26 5f f8 a2 84 3b 46
! DH_r: 22 40 f8 24 46 ec 32 f4 5e 9b 2d 17 d4 a6 02 a0
! DH_r: 9e 47 cc 33 34 90 74 f6 0f 9f 6e 05 5c e3 d6 64
! DH_r: 64 70 5b 50 3b a3 e8 2c 2a 99 78 76 85 c6 91 69
! DH_r: ec 5b 19 af 9e a9 d8 24 6c d7 06 16 d7 84 8e c4
! DH_r: 12 c8 6b ef 3e da a7 2d 85 2f 54 70 d4 5f 59 0d
! DH_r: 91 1e 02 63 57 63 03 5d 1f 9a a2 bb d5 3d 32 fb
! DH_r: c4 93 12 56 09 18 54 ad 6d 04 49 3a d9 48 f9 0e
! end of IV generation
! Skeyid: 71 4a c6 a9 8c db c2 0a 26 47 e9 cf 18 37 f2 5d
! Skeyid_d: 94 8a 24 b3 43 82 b7 72 69 57 d7 60 55 5e 39 4f
! Skeyid_a: 69 e1 1f eb 03 da 5b 76 dd 2b b3 b4 a8 73 d3 2f
! Skeyid_e: e3 6f 10 dd 6c ff 33 69 41 4e 2f 70 3e 6b ef f3
! enc key: 29 71 53 a4 e1 c1 bb 17 90 9e 44 97 2a e7 6a 5c
! enc key: 2a 5d 81 43 f0 f1 8e cd
! IV: 26 c0 b8 d6 27 1c 9c f7 9b 3a cf aa 9e 87 cc c9
|
| helper 2 has finished work (cnt now 1)
| helper 2 replies to id: q#2
| calling callback function 0x7fd1306c80e0
| main inR2_outI3: calculated DH, sending R1
| processing connection verizon
| 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 25 3a 49 62
| emitting length of ISAKMP Identification Payload (IPsec DOI): 12
| hashing 48 bytes of SA
| ***emit ISAKMP Hash Payload:
| next payload type: ISAKMP_NEXT_NONE
| emitting 16 raw bytes of HASH_I into ISAKMP Hash Payload
| HASH_I 7d 95 0a 9b 13 c7 fa 9e a1 bc 21 a6 7f 32 7a e4
| emitting length of ISAKMP Hash Payload: 20
| encrypting:
| 08 00 00 0c 01 00 00 00 25 3a 49 62 00 00 00 14
| 7d 95 0a 9b 13 c7 fa 9e a1 bc 21 a6 7f 32 7a e4
| IV:
| 26 c0 b8 d6 27 1c 9c f7 9b 3a cf aa 9e 87 cc c9
| unpadded size is: 32
| encrypting 32 using OAKLEY_3DES_CBC
| next IV: c8 72 21 64 d6 1b 5e 17
| emitting length of ISAKMP Message: 60
| complete state transition with STF_OK
"verizon" #1: transition from state STATE_MAIN_I2 to state STATE_MAIN_I3
| deleting event for #1
| sending reply packet to IP2:500 (from port 500)
| sending 60 bytes for STATE_MAIN_I2 through bond1:500 to IP2:500 (using #1)
| c6 e6 3b df 9c 8a 6c 3d 19 cd c7 2d a4 f9 12 f1
| 05 10 02 01 00 00 00 00 00 00 00 3c 71 2b f8 2e
| ea 03 40 0d f4 0c 20 83 15 97 a6 d2 c0 de fa f3
| 0c d8 fd 80 c8 72 21 64 d6 1b 5e 17
| inserting event EVENT_RETRANSMIT, timeout in 10 seconds for #1
| event added at head of queue
"verizon" #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 92 bytes from IP2:500 on bond1 (port=500)
| c6 e6 3b df 9c 8a 6c 3d 19 cd c7 2d a4 f9 12 f1
| 08 10 05 01 35 0b de 4b 00 00 00 5c 2c 3e db 67
| fc f9 11 92 09 83 f2 24 ac ed 79 ed e7 c9 9a d2
| 72 a5 d8 0f 12 15 cf 89 7b af 6b c4 eb aa c0 1d
| 0a 02 81 28 1e 64 65 b1 49 46 b7 28 90 ff 81 3e
| 95 66 4e eb bc a7 84 48 19 82 6a 13
| **parse ISAKMP Message:
| initiator cookie:
| c6 e6 3b df 9c 8a 6c 3d
| responder cookie:
| 19 cd c7 2d a4 f9 12 f1
| next payload type: ISAKMP_NEXT_HASH
| ISAKMP version: ISAKMP Version 1.0 (rfc2407)
| exchange type: ISAKMP_XCHG_INFO
| flags: ISAKMP_FLAG_ENCRYPTION
| message ID: 35 0b de 4b
| length: 92
| processing version=1.0 packet with exchange type=ISAKMP_XCHG_INFO (5)
| ICOOKIE: c6 e6 3b df 9c 8a 6c 3d
| RCOOKIE: 19 cd c7 2d a4 f9 12 f1
| state hash entry 9
| peer and cookies match on #1, provided msgid 00000000 vs 00000000/00000000
| p15 state object #1 found, in STATE_MAIN_I3
| processing connection verizon
| last Phase 1 IV:
| current Phase 1 IV: c8 72 21 64 d6 1b 5e 17
| computed Phase 2 IV:
| e4 03 fd de 26 b5 12 e2 e0 b8 ae ef d5 15 b7 40
| received encrypted packet from IP2:500
| decrypting 64 bytes using algorithm OAKLEY_3DES_CBC
| decrypted:
| d1 c8 2a d2 4e 86 2c 59 48 16 b9 df db 09 e6 26
| f6 dc 99 6a b9 f9 13 2a 98 eb ca 47 dc e3 58 53
| 76 2c 7d 7e 97 97 8b 26 23 e1 de 1a f8 4e 26 b3
| ed 4f 95 0c f4 c4 68 2d e9 eb b7 98 68 51 d3 cb
| next IV: bc a7 84 48 19 82 6a 13
| got payload 0x100(ISAKMP_NEXT_HASH) needed: 0x100 opt: 0x0
"verizon" #1: next payload type of ISAKMP Hash Payload has an unknown value: 209
"verizon" #1: malformed payload in packet
| payload malformed after IV
| c8 72 21 64 d6 1b 5e 17
"verizon" #1: sending notification PAYLOAD_MALFORMED to IP2:500
| **emit ISAKMP Message:
| initiator cookie:
| c6 e6 3b df 9c 8a 6c 3d
| responder cookie:
| 19 cd c7 2d a4 f9 12 f1
| next payload type: ISAKMP_NEXT_N
| ISAKMP version: ISAKMP Version 1.0 (rfc2407)
| exchange type: ISAKMP_XCHG_INFO
| flags: none
| message ID: 50 04 78 0e
| ***emit ISAKMP Notification Payload:
| next payload type: ISAKMP_NEXT_NONE
| DOI: ISAKMP_DOI_IPSEC
| protocol ID: 1
| SPI size: 0
| Notify Message Type: PAYLOAD_MALFORMED
| emitting length of ISAKMP Notification Payload: 12
| emitting length of ISAKMP Message: 40
| sending 40 bytes for notification packet through bond1:500 to IP2:500 (using #1)
| c6 e6 3b df 9c 8a 6c 3d 19 cd c7 2d a4 f9 12 f1
| 0b 10 05 00 50 04 78 0e 00 00 00 28 00 00 00 0c
| 00 00 00 01 01 00 00 10
| * 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 196 bytes from IP2:500 on bond1 (port=500)
| d8 8f 11 72 7a 18 65 04 d7 e4 3c 41 49 13 bd 83
| 04 10 02 00 00 00 00 00 00 00 00 c4 0a 00 00 84
| 70 f9 0c 4a 7d 11 62 3f bf c2 f1 de 60 4d f9 44
| 7f 2b bb f6 4c 60 c1 24 97 33 5c 04 f7 9e 62 69
| 53 5b 5e da 9c b8 c9 08 79 60 b3 f4 09 f4 73 3e
| 0e 9a d4 aa 56 42 7c 6a 61 57 46 49 57 11 5e a5
| df 62 a2 d0 43 ac 1d 55 59 c4 5a 45 5b cc 5f dd
| bb c7 51 6e 84 01 47 da 8c e9 26 34 7d b0 61 4c
| d4 19 07 b6 68 41 4d bb 2f 30 41 09 77 6a 1c 70
| 67 bd 7e 4b a3 79 86 fc 3c de 8f 64 36 d9 0c 56
| 00 00 00 24 7a 26 c6 f6 a0 4c a7 c0 05 04 92 7e
| b5 24 92 d0 2f e2 b0 f2 80 08 1d 3e 27 e5 de 18
| 83 c3 97 31
| **parse ISAKMP Message:
| initiator cookie:
| d8 8f 11 72 7a 18 65 04
| responder cookie:
| d7 e4 3c 41 49 13 bd 83
| 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: 196
| processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
| ICOOKIE: d8 8f 11 72 7a 18 65 04
| RCOOKIE: d7 e4 3c 41 49 13 bd 83
| state hash entry 15
| v1 state object not found
| ICOOKIE: d8 8f 11 72 7a 18 65 04
| RCOOKIE: 00 00 00 00 00 00 00 00
| state hash entry 5
| v1 state object not found
packet from IP2:500: phase 1 message is part of an unknown exchange
| * processed 0 messages from cryptographic helpers
| next event EVENT_RETRANSMIT in 8 seconds for #1
| next event EVENT_RETRANSMIT in 8 seconds for #1
I also obtained the logs from their side:
## 2015-05-29 11:04:56 : IKE<IP1> ike packet, len 144, action 1
## 2015-05-29 11:04:56 : IKE<IP1> Catcher: received 116 bytes from socket.
## 2015-05-29 11:04:56 : IKE<IP1> ****** Recv packet if <redundant1.100:1> of vsys <Root> ******
## 2015-05-29 11:04:56 : IKE<IP1> Catcher: get 116 bytes. src port 500
## 2015-05-29 11:04:56 : IKE<IP1 > Recv : [SA] [VID] [VID]
## 2015-05-29 11:04:56 : IKE<IP1> found peer vpn-15096 at ISCIP_DESSN1_CUST
## 2015-05-29 11:04:56 : IKE<IP1> Found peer entry (vpn-15096 at ISCIP_DESSN1_CUST) from IP1.
## 2015-05-29 11:04:56 : responder create sa: IP1->IP2
## 2015-05-29 11:04:56 : IKE<IP1> getProfileFromP1Proposal->
## 2015-05-29 11:04:56 : IKE<IP1> find profile[0]=<00000005 00000001 00000001 00000002> for p1 proposal (id 4), xauth(0)
## 2015-05-29 11:04:56 : IKE<IP1> find profile[1]=<00000005 00000002 00000001 00000002> for p1 proposal (id 5), xauth(0)
## 2015-05-29 11:04:56 : IKE<IP1> find profile[2]=<00000007 00000001 00000001 00000002> for p1 proposal (id 6), xauth(0)
## 2015-05-29 11:04:56 : IKE<IP1> find profile[3]=<00000007 00000002 00000001 00000002> for p1 proposal (id 7), xauth(0)
## 2015-05-29 11:04:56 : IKE<IP1> responder create sa: IP1->IP2
## 2015-05-29 11:04:56 : IKE<IP1> Phase 1: Responder starts MAIN mode negotiations.
## 2015-05-29 11:04:56 : IKE<IP1> MM in state OAK_MM_NO_STATE.
## 2015-05-29 11:04:56 : IKE<IP1> Process [VID]:
## 2015-05-29 11:04:56 : IKE<IP1 > Vendor ID:
## 2015-05-29 11:04:56 : IKE<IP1> receive unknown vendor ID payload
## 2015-05-29 11:04:56 : IKE<IP1> Process [VID]:
## 2015-05-29 11:04:56 : IKE<IP1 > Vendor ID:
## 2015-05-29 11:04:56 : IKE<IP1> Process [SA]:
## 2015-05-29 11:04:56 : IKE<IP1> Proposal received: xauthflag 0
## 2015-05-29 11:04:56 : IKE<IP1> auth(1)<PRESHRD>, encr(5)<3DES>, hash(2)<SHA>, group(2)
## 2015-05-29 11:04:56 : IKE<IP1> xauth attribute: disabled
## 2015-05-29 11:04:56 : IKE<IP1> [0] expect: xauthflag 0
## 2015-05-29 11:04:56 : IKE<IP1> auth(1)<PRESHRD>, encr(5)<3DES>, hash(1)<MD5>, group(2)
## 2015-05-29 11:04:56 : IKE<IP1> xauth attribute: disabled
## 2015-05-29 11:04:56 : IKE<IP1> Phase 1 proposal [1] selected.
## 2015-05-29 11:04:56 : IKE<IP1> SA Life Type = seconds
## 2015-05-29 11:04:56 : IKE<IP1> SA lifetime (TV) = 3600
## 2015-05-29 11:04:56 : IKE<IP1> DH_BG_consume OK. p1 resp
## 2015-05-29 11:04:56 : IKE<IP1> Phase 1 MM Responder constructing 2nd message.
## 2015-05-29 11:04:56 : IKE<IP1> Construct ISAKMP header.
## 2015-05-29 11:04:56 : IKE<IP1> Msg header built (next payload #1)
## 2015-05-29 11:04:56 : IKE<IP1> Construct [SA] for ISAKMP
## 2015-05-29 11:04:56 : IKE<IP1> auth(1)<PRESHRD>, encr(5)<3DES>, hash(2)<SHA>, group(2)
## 2015-05-29 11:04:56 : IKE<IP1> xauth attribute: disabled
## 2015-05-29 11:04:56 : IKE<IP1> lifetime/lifesize (3600/0)
## 2015-05-29 11:04:56 : IKE<IP1> Construct NetScreen [VID]
## 2015-05-29 11:04:56 : IKE<IP1> Construct custom [VID]
## 2015-05-29 11:04:56 : IKE<IP1> Construct custom [VID]
## 2015-05-29 11:04:56 : IKE<IP1 > Xmit : [SA] [VID] [VID] [VID]
## 2015-05-29 11:04:56 : IKE<IP1> Responder sending IPv4 IP IP1/port 500
## 2015-05-29 11:04:56 : IKE<IP1> Send Phase 1 packet (len=156)
## 2015-05-29 11:04:56 : IKE<IP1> IKE msg done: PKI state<0> IKE state<1/800003>
## 2015-05-29 11:04:56 : IKE<IP1> ike packet, len 208, action 0
## 2015-05-29 11:04:56 : IKE<IP1> Catcher: received 180 bytes from socket.
## 2015-05-29 11:04:56 : IKE<IP1> ****** Recv packet if <redundant1.100:1> of vsys <Root> ******
## 2015-05-29 11:04:56 : IKE<IP1> Catcher: get 180 bytes. src port 500
## 2015-05-29 11:04:56 : IKE<IP1 > Recv : [KE] [NONCE]
## 2015-05-29 11:04:56 : IKE<IP1> MM in state OAK_MM_SA_SETUP.
## 2015-05-29 11:04:56 : IKE<IP1> Process [KE]:
## 2015-05-29 11:04:56 : IKE<IP1> processing ISA_KE in phase 1.
## 2015-05-29 11:04:56 : IKE<IP1> Phase1: his_DH_pub_len is 128
## 2015-05-29 11:04:56 : IKE<IP1> Process [NONCE]:
## 2015-05-29 11:04:56 : IKE<IP1> processing NONCE in phase 1.
## 2015-05-29 11:04:56 : IKE<IP1> IKE msg done: PKI state<0> IKE state<1/280200b>
## 2015-05-29 11:04:56 : IKE<IP1> MM in state OAK_MM_SA_SETUP.
## 2015-05-29 11:04:56 : IKE<IP1> re-enter MM after offline DH done
## 2015-05-29 11:04:56 : IKE<IP1> Phase 1 MM Responder constructing 4th message.
## 2015-05-29 11:04:56 : IKE<IP1> Construct ISAKMP header.
## 2015-05-29 11:04:56 : IKE<IP1> Msg header built (next payload #4)
## 2015-05-29 11:04:56 : IKE<IP1> Construct [KE] for ISAKMP
## 2015-05-29 11:04:56 : IKE<IP1> Construct [NONCE]
## 2015-05-29 11:04:56 : IKE<IP1> throw packet to the peer, paket_len=196
## 2015-05-29 11:04:56 : IKE<IP1 > Xmit : [KE] [NONCE]
## 2015-05-29 11:04:56 : IKE<IP1> Responder sending IPv4 IP IP1/port 500
## 2015-05-29 11:04:56 : IKE<IP1> Send Phase 1 packet (len=196)
## 2015-05-29 11:04:56 : IKE<IP1> ike packet, len 96, action 0
## 2015-05-29 11:04:56 : IKE<IP1> Catcher: received 68 bytes from socket.
## 2015-05-29 11:04:56 : IKE<IP1> ****** Recv packet if <redundant1.100:1> of vsys <Root> ******
## 2015-05-29 11:04:56 : IKE<IP1> Catcher: get 68 bytes. src port 500
## 2015-05-29 11:04:56 : IKE<IP1> gen_skeyid()
## 2015-05-29 11:04:56 : IKE<IP1> gen_skeyid: returning 0
## 2015-05-29 11:04:56 : IKE<IP1> Decrypting payload (length 40)
## 2015-05-29 11:04:56 : IKE<IP1 > Recv*: [ID] +++ Corrupted MSG
## 2015-05-29 11:04:56 : IKE<IP1> Packet is invalid!
## 2015-05-29 11:04:56 : IKE<IP1> Pre-shared key might not match.
## 2015-05-29 11:04:56 : IKE<IP1> Create conn entry...
## 2015-05-29 11:04:56 : IKE<IP1> ...done(new 9a80335d)
## 2015-05-29 11:04:56 : IKE<IP1> Construct ISAKMP header.
## 2015-05-29 11:04:56 : IKE<IP1> Msg header built (next payload #8)
## 2015-05-29 11:04:56 : IKE<IP1> Construct [HASH]
## 2015-05-29 11:04:56 : IKE<IP1> Construct [NOTIF]:(PAYLOAD-MALFORMED)
## 2015-05-29 11:04:56 : IKE<IP1> construct QM HASH
## 2015-05-29 11:04:56 : IKE<IP1 > Xmit*: [HASH] [NOTIF]
## 2015-05-29 11:04:56 : IKE<IP1> Encrypt P2 payload (len 88)
## 2015-05-29 11:04:56 : IKE<IP1> Responder sending IPv4 IP IP1/port 500
## 2015-05-29 11:04:56 : IKE<IP1> Send Phase 2 packet (len=92)
## 2015-05-29 11:04:56 : IKE<IP1> Delete conn entry...
## 2015-05-29 11:04:56 : IKE<IP1> ...found conn entry(9a80335d)
## 2015-05-29 11:04:56 : IKE<IP1> ike packet, len 68, action 0
## 2015-05-29 11:04:56 : IKE<IP1> Catcher: received 40 bytes from socket.
## 2015-05-29 11:04:56 : IKE<IP1> ****** Recv packet if <redundant1.100:1> of vsys <Root> ******
## 2015-05-29 11:04:56 : IKE<IP1> Catcher: get 40 bytes. src port 500
## 2015-05-29 11:04:56 : IKE<IP1 > Recv : [NOTIF]
## 2015-05-29 11:04:56 : IKE<IP1> receive pkt with mseeage id before phase 1 auth is done. Ingore the pkt
## 2015-05-29 11:05:00 : IKE<IP1> re-trans timer expired, msg retry (0) (80100f/2)
## 2015-05-29 11:05:00 : IKE<IP1> Responder sending IPv4 IP IP1/port 500
## 2015-05-29 11:05:00 : IKE<IP1> Send Phase 1 packet (len=196)
## 2015-05-29 11:05:03 : IKE<IP1> xauth_cleanup()
## 2015-05-29 11:05:03 : IKE<IP1> Done cleaning up IKE Phase 1 SA
## 2015-05-29 11:05:04 : IKE<IP1> re-trans timer expired, msg retry (1) (80100f/2)
## 2015-05-29 11:05:04 : IKE<IP1> Responder sending IPv4 IP IP1/port 500
## 2015-05-29 11:05:04 : IKE<IP1> Send Phase 1 packet (len=196)
## 2015-05-29 11:05:06 : IKE<IP1> ike packet, len 96, action 0
## 2015-05-29 11:05:06 : IKE<IP1> Catcher: received 68 bytes from socket.
## 2015-05-29 11:05:06 : IKE<IP1> ****** Recv packet if <redundant1.100:1> of vsys <Root> ******
## 2015-05-29 11:05:06 : IKE<IP1> Catcher: get 68 bytes. src port 500
## 2015-05-29 11:05:06 : IKE<IP1> Receive re-transmit IKE packet phase 1 SA(IP1) exchg(2) len(68)
## 2015-05-29 11:05:08 : IKE<IP1> re-trans timer expired, msg retry (2) (80100f/2)
## 2015-05-29 11:05:08 : IKE<IP1> Responder sending IPv4 IP IP1/port 500
## 2015-05-29 11:05:08 : IKE<IP1> Send Phase 1 packet (len=196)
## 2015-05-29 11:05:12 : IKE<IP1> re-trans timer expired, msg retry (3) (80100f/2)
## 2015-05-29 11:05:12 : IKE<IP1> Responder sending IPv4 IP IP1/port 500
## 2015-05-29 11:05:12 : IKE<IP1> Send Phase 1 packet (len=196)
## 2015-05-29 11:05:14 : IKE<IP1> ****** Recv kernel msg IDX-17, TYPE-5 ******
## 2015-05-29 11:05:14 : IKE<IP1> ****** Recv kernel msg IDX-17, TYPE-5 ******
## 2015-05-29 11:05:14 : IKE<IP1> sa orig index<17>, peer_id<15>.
## 2015-05-29 11:05:14 : IKE<IP1> isadb_get_entry_by_peer_and_local_if_port_p2sa isadb get entry by peer/local ip and port
## 2015-05-29 11:05:14 : IKE<IP1> Added Phase 2 session tasks to the task list.
## 2015-05-29 11:05:16 : IKE<IP1> re-trans timer expired, msg retry (4) (80100f/2)
## 2015-05-29 11:05:16 : IKE<IP1> Responder sending IPv4 IP IP1/port 500
## 2015-05-29 11:05:16 : IKE<IP1> Send Phase 1 packet (len=196)
## 2015-05-29 11:05:20 : IKE<IP1> re-trans timer expired, msg retry (5) (80100f/2)
## 2015-05-29 11:05:20 : IKE<IP1> Responder sending IPv4 IP IP1/port 500
## 2015-05-29 11:05:20 : IKE<IP1> Send Phase 1 packet (len=196)
## 2015-05-29 11:05:24 : IKE<IP1> re-trans timer expired, msg retry (6) (80100f/2)
## 2015-05-29 11:05:24 : IKE<IP1> Responder sending IPv4 IP IP1/port 500
## 2015-05-29 11:05:24 : IKE<IP1> Send Phase 1 packet (len=196)
## 2015-05-29 11:05:26 : IKE<IP1> ike packet, len 96, action 0
## 2015-05-29 11:05:26 : IKE<IP1> Catcher: received 68 bytes from socket.
## 2015-05-29 11:05:26 : IKE<IP1> ****** Recv packet if <redundant1.100:1> of vsys <Root> ******
## 2015-05-29 11:05:26 : IKE<IP1> Catcher: get 68 bytes. src port 500
## 2015-05-29 11:05:26 : IKE<IP1> Receive re-transmit IKE packet phase 1 SA(IP1) exchg(2) len(68)
## 2015-05-29 11:05:28 : IKE<IP1> re-trans timer expired, msg retry (7) (80100f/2)
## 2015-05-29 11:05:28 : IKE<IP1> Responder sending IPv4 IP IP1/port 500
## 2015-05-29 11:05:28 : IKE<IP1> Send Phase 1 packet (len=196)
Thank you,
Alex
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.openswan.org/pipermail/users/attachments/20150603/a90e210f/attachment-0001.html>
More information about the Users
mailing list