[Swan] modecfg with multiple subnets
Wolfgang Nothdurft
wolfgang at linogate.de
Mon Jun 16 16:51:50 EEST 2014
Hi,
I was trying to configure mode config with multiple subnets.
The problem is that the connection with the second subnet can't connect
(see log and example config):
Jun 16 15:45:05 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: cannot
respond to IPsec SA request because no connection is known for
192.168.11.0/24===10.0.11.2[MS+S=C]...10.0.12.2[+MC+S=C]===192.168.12.1/32
Should it be possible to use mode config with multiple subnets?
And there seems to be an old bug also that rightsubnet needs to be set
with leftsubnets and vice versa.
This would be problematic if you'd use rightaddresspool instead of
rightsubnet on the server side.
Wolfgang
-------------- next part --------------
conn client
left=%defaultroute
leftsubnets={192.168.11.0/24 192.168.111.0/24}
right=%any
auto=add
keyingtries=0
authby=secret
auth=esp
leftmodecfgserver=yes
rightmodecfgclient=yes
modecfgpull=yes
rightsubnet=192.168.13.100/32
-------------- next part --------------
conn server
left=%defaultroute
leftsubnet=192.168.12.1/32
right=10.0.11.2
rightsubnets={192.168.11.0/24 192.168.111.0/24}
auto=add
authby=secret
modecfgpull=yes
leftmodecfgclient=yes
rightmodecfgserver=yes
-------------- next part --------------
Jun 16 15:36:48 d1 pluto[27759]: Using sql format key4.db, cert9.db
Jun 16 15:36:48 d1 pluto[27759]: Initializing NSS: DB is sql:/etc/ipsec.d
Jun 16 15:36:48 d1 pluto[27759]: NSS initialized
Jun 16 15:36:48 d1 pluto[27759]: libcap-ng support [disabled]
Jun 16 15:36:48 d1 pluto[27759]: FIPS HMAC integrity support [disabled]
Jun 16 15:36:48 d1 pluto[27759]: Linux audit support [disabled]
Jun 16 15:36:48 d1 pluto[27759]: Starting Pluto (Libreswan Version 3.master-201425.git XFRM(netkey) KLIPS NSS XAUTH_PAM KLIPS_MAST) pid:27759
Jun 16 15:36:48 d1 pluto[27759]: core dump dir: /var/run/pluto
Jun 16 15:36:48 d1 pluto[27759]: secrets file: /etc/ipsec.secrets
Jun 16 15:36:48 d1 pluto[27759]: leak-detective disabled
Jun 16 15:36:48 d1 pluto[27759]: SAref support [enabled]
Jun 16 15:36:48 d1 pluto[27759]: SAbind support [enabled]
Jun 16 15:36:48 d1 pluto[27759]: NSS crypto [enabled]
Jun 16 15:36:48 d1 pluto[27759]: XAUTH PAM support [enabled]
Jun 16 15:36:48 d1 pluto[27759]: NAT-Traversal support [enabled]
Jun 16 15:36:48 d1 pluto[27759]: | inserting event EVENT_REINIT_SECRET, timeout in 3600 seconds
Jun 16 15:36:48 d1 pluto[27759]: | event added at head of queue
Jun 16 15:36:48 d1 pluto[27759]: | inserting event EVENT_PENDING_DDNS, timeout in 60 seconds
Jun 16 15:36:48 d1 pluto[27759]: | event added at head of queue
Jun 16 15:36:48 d1 pluto[27759]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
Jun 16 15:36:48 d1 pluto[27759]: | event added after event EVENT_PENDING_DDNS
Jun 16 15:36:48 d1 pluto[27759]: ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC_SSH: Ok (ret=0)
Jun 16 15:36:48 d1 pluto[27759]: ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC: Ok (ret=0)
Jun 16 15:36:48 d1 pluto[27759]: ike_alg_register_enc(): Activating OAKLEY_SERPENT_CBC: Ok (ret=0)
Jun 16 15:36:48 d1 pluto[27759]: ike_alg_register_enc(): Activating OAKLEY_AES_CBC: Ok (ret=0)
Jun 16 15:36:48 d1 pluto[27759]: ike_alg_register_hash(): Activating OAKLEY_SHA2_512: Ok (ret=0)
Jun 16 15:36:48 d1 pluto[27759]: ike_alg_register_hash(): Activating OAKLEY_SHA2_384: Ok (ret=0)
Jun 16 15:36:48 d1 pluto[27759]: ike_alg_register_hash(): Activating OAKLEY_SHA2_256: Ok (ret=0)
Jun 16 15:36:48 d1 pluto[27759]: no crypto helpers will be started; all cryptographic operations will be done inline
Jun 16 15:36:48 d1 pluto[27759]: Using KLIPS IPsec interface code on 2.6.32.62
Jun 16 15:36:48 d1 pluto[27759]: | inserting event EVENT_SHUNT_SCAN, timeout in 120 seconds
Jun 16 15:36:48 d1 pluto[27759]: | event added after event EVENT_PENDING_DDNS
Jun 16 15:36:48 d1 pluto[27759]: | Changed path to directory '/etc/ipsec.d/cacerts'
Jun 16 15:36:48 d1 pluto[27759]: loading CA cert file 'server.crt' (1701 bytes)
Jun 16 15:36:48 d1 pluto[27759]: | TRUE
Jun 16 15:36:48 d1 pluto[27759]: loading CA cert file 'ca.crt' (2366 bytes)
Jun 16 15:36:48 d1 pluto[27759]: | TRUE
Jun 16 15:36:48 d1 pluto[27759]: | Changing to directory '/etc/ipsec.d/crls'
Jun 16 15:36:48 d1 pluto[27759]: discarded crl file 'server.crl', bad size 0 bytes
Jun 16 15:36:48 d1 pluto[27759]: | inserting event EVENT_LOG_DAILY, timeout in 30192 seconds
Jun 16 15:36:48 d1 pluto[27759]: | event added after event EVENT_REINIT_SECRET
Jun 16 15:36:48 d1 pluto[27759]: listening for IKE messages
Jun 16 15:36:48 d1 pluto[27759]: | Inspecting interface lo
Jun 16 15:36:48 d1 pluto[27759]: | found lo with address 127.0.0.1
Jun 16 15:36:48 d1 pluto[27759]: | Inspecting interface eth1
Jun 16 15:36:48 d1 pluto[27759]: | found eth1 with address 10.0.11.2
Jun 16 15:36:48 d1 pluto[27759]: | Inspecting interface eth0
Jun 16 15:36:48 d1 pluto[27759]: | found eth0 with address 192.168.11.1
Jun 16 15:36:48 d1 pluto[27759]: | Inspecting interface eth2
Jun 16 15:36:48 d1 pluto[27759]: | found eth2 with address 172.16.16.2
Jun 16 15:36:48 d1 pluto[27759]: | Inspecting interface eth3
Jun 16 15:36:48 d1 pluto[27759]: | found eth3 with address 192.168.192.111
Jun 16 15:36:48 d1 pluto[27759]: | Inspecting interface ipsec0
Jun 16 15:36:48 d1 pluto[27759]: | found ipsec0 with address 10.0.11.2
Jun 16 15:36:48 d1 pluto[27759]: | IP interface eth3 192.168.192.111 has no matching ipsec* interface -- ignored
Jun 16 15:36:48 d1 pluto[27759]: | IP interface eth2 172.16.16.2 has no matching ipsec* interface -- ignored
Jun 16 15:36:48 d1 pluto[27759]: | IP interface eth0 192.168.11.1 has no matching ipsec* interface -- ignored
Jun 16 15:36:48 d1 pluto[27759]: adding interface ipsec0/eth1 10.0.11.2:500
Jun 16 15:36:48 d1 pluto[27759]: adding interface ipsec0/eth1 10.0.11.2:4500
Jun 16 15:36:48 d1 pluto[27759]: | IP interface lo 127.0.0.1 has no matching ipsec* interface -- ignored
Jun 16 15:36:48 d1 pluto[27759]: | could not open /proc/net/if_inet6
Jun 16 15:36:48 d1 pluto[27759]: | certs and keys locked by 'free_preshared_secrets'
Jun 16 15:36:48 d1 pluto[27759]: | certs and keys unlocked by 'free_preshard_secrets'
Jun 16 15:36:48 d1 pluto[27759]: loading secrets from "/etc/ipsec.secrets"
Jun 16 15:36:48 d1 pluto[27759]: could not open host cert with nick name '/etc/ipsec.d/server.crt' in NSS DB
Jun 16 15:36:48 d1 pluto[27759]: "/etc/ipsec.secrets" line 2: NSS certficate not found
Jun 16 15:36:48 d1 pluto[27759]: loaded private key for keyid: PPK_RSA:AwEAAaBJJ
Jun 16 15:36:48 d1 pluto[27759]: | certs and keys locked by 'process_secret'
Jun 16 15:36:48 d1 pluto[27759]: | certs and keys unlocked by 'process_secret'
Jun 16 15:36:48 d1 pluto[27759]: loading secrets from "/etc/ipsec.d/client-0-client.psk"
Jun 16 15:36:48 d1 pluto[27759]: | Processing PSK at line 1: passed
Jun 16 15:36:48 d1 pluto[27759]: | certs and keys locked by 'process_secret'
Jun 16 15:36:48 d1 pluto[27759]: | certs and keys unlocked by 'process_secret'
Jun 16 15:36:48 d1 pluto[27759]: | next event EVENT_PENDING_DDNS in 60 seconds
Jun 16 15:36:49 d1 pluto[27761]: | calling addconn helper using execve
Jun 16 15:36:49 d1 pluto[27759]: |
Jun 16 15:36:49 d1 pluto[27759]: | *received whack message
Jun 16 15:36:49 d1 pluto[27759]: | find_host_pair_conn (check_connection_end): 10.0.11.2:500 %any:500 -> hp:none
Jun 16 15:36:49 d1 pluto[27759]: | Added new connection client/1x0 with policy PSK+ENCRYPT+TUNNEL+PFS+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW
Jun 16 15:36:49 d1 pluto[27759]: | counting wild cards for (none) is 15
Jun 16 15:36:49 d1 pluto[27759]: | counting wild cards for (none) is 15
Jun 16 15:36:49 d1 pluto[27759]: | based upon policy, the connection is a template.
Jun 16 15:36:49 d1 pluto[27759]: | connect_to_host_pair: 10.0.11.2:500 0.0.0.0:500 -> hp:none
Jun 16 15:36:49 d1 pluto[27759]: added connection description "client/1x0"
Jun 16 15:36:49 d1 pluto[27759]: | 192.168.11.0/24===10.0.11.2[MS+S=C]---10.0.11.1...%any[+MC+S=C]===192.168.13.100/32
Jun 16 15:36:49 d1 pluto[27759]: | ike_life: 3600s; ipsec_life: 28800s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0; policy: PSK+ENCRYPT+TUNNEL+PFS+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW
Jun 16 15:36:49 d1 pluto[27759]: | * processed 0 messages from cryptographic helpers
Jun 16 15:36:49 d1 pluto[27759]: | next event EVENT_PENDING_DDNS in 59 seconds
Jun 16 15:36:49 d1 pluto[27759]: | next event EVENT_PENDING_DDNS in 59 seconds
Jun 16 15:36:49 d1 pluto[27759]: |
Jun 16 15:36:49 d1 pluto[27759]: | *received whack message
Jun 16 15:36:49 d1 pluto[27759]: | find_host_pair: comparing to 10.0.11.2:500 0.0.0.0:500
Jun 16 15:36:49 d1 pluto[27759]: | find_host_pair_conn (check_connection_end): 10.0.11.2:500 %any:500 -> hp:client/1x0
Jun 16 15:36:49 d1 pluto[27759]: | Added new connection client/2x0 with policy PSK+ENCRYPT+TUNNEL+PFS+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW
Jun 16 15:36:49 d1 pluto[27759]: | counting wild cards for (none) is 15
Jun 16 15:36:49 d1 pluto[27759]: | counting wild cards for (none) is 15
Jun 16 15:36:49 d1 pluto[27759]: | based upon policy, the connection is a template.
Jun 16 15:36:49 d1 pluto[27759]: | find_host_pair: comparing to 10.0.11.2:500 0.0.0.0:500
Jun 16 15:36:49 d1 pluto[27759]: | connect_to_host_pair: 10.0.11.2:500 0.0.0.0:500 -> hp:client/1x0
Jun 16 15:36:49 d1 pluto[27759]: added connection description "client/2x0"
Jun 16 15:36:49 d1 pluto[27759]: | 192.168.111.0/24===10.0.11.2[MS+S=C]---10.0.11.1...%any[+MC+S=C]===192.168.13.100/32
Jun 16 15:36:49 d1 pluto[27759]: | ike_life: 3600s; ipsec_life: 28800s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0; policy: PSK+ENCRYPT+TUNNEL+PFS+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW
Jun 16 15:36:49 d1 pluto[27759]: | * processed 0 messages from cryptographic helpers
Jun 16 15:36:49 d1 pluto[27759]: | next event EVENT_PENDING_DDNS in 59 seconds
Jun 16 15:36:49 d1 pluto[27759]: | next event EVENT_PENDING_DDNS in 59 seconds
Jun 16 15:36:49 d1 pluto[27759]: | next event EVENT_PENDING_DDNS in 59 seconds
Jun 16 15:36:49 d1 pluto[27759]: | reaped addconn helper child
Jun 16 15:36:54 d1 pluto[27759]: |
Jun 16 15:36:54 d1 pluto[27759]: | *received 576 bytes from 10.0.12.2:500 on eth1 (port=500)
Jun 16 15:36:54 d1 pluto[27759]: | processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
Jun 16 15:36:54 d1 pluto[27759]: packet from 10.0.12.2:500: received Vendor ID payload [Dead Peer Detection]
Jun 16 15:36:54 d1 pluto[27759]: packet from 10.0.12.2:500: received Vendor ID payload [FRAGMENTATION]
Jun 16 15:36:54 d1 pluto[27759]: packet from 10.0.12.2:500: received Vendor ID payload [RFC 3947]
Jun 16 15:36:54 d1 pluto[27759]: packet from 10.0.12.2:500: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03]
Jun 16 15:36:54 d1 pluto[27759]: packet from 10.0.12.2:500: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]
Jun 16 15:36:54 d1 pluto[27759]: packet from 10.0.12.2:500: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02]
Jun 16 15:36:54 d1 pluto[27759]: | find_host_connection me=10.0.11.2:500 him=10.0.12.2:500 policy=none
Jun 16 15:36:54 d1 pluto[27759]: | find_host_pair: comparing to 10.0.11.2:500 0.0.0.0:500
Jun 16 15:36:54 d1 pluto[27759]: | find_host_pair_conn (find_host_connection): 10.0.11.2:500 10.0.12.2:500 -> hp:none
Jun 16 15:36:54 d1 pluto[27759]: | find_host_connection returns empty
Jun 16 15:36:54 d1 pluto[27759]: | find_host_connection me=10.0.11.2:500 him=%any:500 policy=PSK
Jun 16 15:36:54 d1 pluto[27759]: | find_host_pair: comparing to 10.0.11.2:500 0.0.0.0:500
Jun 16 15:36:54 d1 pluto[27759]: | find_host_pair_conn (find_host_connection): 10.0.11.2:500 %any:500 -> hp:client/2x0
Jun 16 15:36:54 d1 pluto[27759]: | searching for connection with policy = PSK
Jun 16 15:36:54 d1 pluto[27759]: | found policy = PSK+ENCRYPT+TUNNEL+PFS+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW (client/2x0)
Jun 16 15:36:54 d1 pluto[27759]: | find_host_connection returns client/2x0
Jun 16 15:36:54 d1 pluto[27759]: | instantiating "client/2x0" for initial Main Mode message received on 10.0.11.2:500
Jun 16 15:36:54 d1 pluto[27759]: | find_host_pair: comparing to 10.0.11.2:500 0.0.0.0:500
Jun 16 15:36:54 d1 pluto[27759]: | connect_to_host_pair: 10.0.11.2:500 10.0.12.2:500 -> hp:none
Jun 16 15:36:54 d1 pluto[27759]: | instantiated "client/2x0" for 10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | creating state object #1 at 0xb7835ca0
Jun 16 15:36:54 d1 pluto[27759]: | processing connection client/2x0[1] 10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | ICOOKIE: 20 99 a2 35 d5 da 79 ce
Jun 16 15:36:54 d1 pluto[27759]: | RCOOKIE: fe 19 ee 98 16 6c 12 39
Jun 16 15:36:54 d1 pluto[27759]: | state hash entry 24
Jun 16 15:36:54 d1 pluto[27759]: | inserting state object #1
Jun 16 15:36:54 d1 pluto[27759]: | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #1
Jun 16 15:36:54 d1 pluto[27759]: | event added at head of queue
Jun 16 15:36:54 d1 pluto[27759]: | sender checking NAT-t: enabled and 83
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: enabling possible NAT-traversal with method RFC 3947 (NAT-Traversal)
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: responding to Main Mode from unknown peer 10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | started looking for secret for 10.0.11.2->10.0.12.2 of kind PPK_PSK
Jun 16 15:36:54 d1 pluto[27759]: | actually looking for secret for 10.0.11.2->10.0.12.2 of kind PPK_PSK
Jun 16 15:36:54 d1 pluto[27759]: | line 1: key type PPK_PSK(10.0.11.2) to type PPK_PSK
Jun 16 15:36:54 d1 pluto[27759]: | 1: compared key (none) to 10.0.11.2 / 10.0.12.2 -> 2
Jun 16 15:36:54 d1 pluto[27759]: | 2: compared key (none) to 10.0.11.2 / 10.0.12.2 -> 2
Jun 16 15:36:54 d1 pluto[27759]: | line 1: match=2
Jun 16 15:36:54 d1 pluto[27759]: | best_match 0>2 best=0xb7838e70 (line=1)
Jun 16 15:36:54 d1 pluto[27759]: | line 2: key type PPK_PSK(10.0.11.2) to type PPK_RSA
Jun 16 15:36:54 d1 pluto[27759]: | concluding with best_match=2 best=0xb7838e70 (lineno=1)
Jun 16 15:36:54 d1 pluto[27759]: | no IKE message padding required
Jun 16 15:36:54 d1 pluto[27759]: | peer supports fragmentation
Jun 16 15:36:54 d1 pluto[27759]: | complete state transition with STF_OK
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
Jun 16 15:36:54 d1 pluto[27759]: | deleting event for #1
Jun 16 15:36:54 d1 pluto[27759]: | sending reply packet to 10.0.12.2:500 (from port 500)
Jun 16 15:36:54 d1 pluto[27759]: | sending 144 bytes for STATE_MAIN_R0 through eth1:500 to 10.0.12.2:500 (using #1)
Jun 16 15:36:54 d1 pluto[27759]: | inserting event EVENT_v1_RETRANSMIT, timeout in 10 seconds for #1
Jun 16 15:36:54 d1 pluto[27759]: | event added at head of queue
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: STATE_MAIN_R1: sent MR1, expecting MI2
Jun 16 15:36:54 d1 pluto[27759]: | modecfg pull: noquirk policy:pull not-client
Jun 16 15:36:54 d1 pluto[27759]: | phase 1 is done, looking for phase 2 to unpend
Jun 16 15:36:54 d1 pluto[27759]: | * processed 0 messages from cryptographic helpers
Jun 16 15:36:54 d1 pluto[27759]: | next event EVENT_v1_RETRANSMIT in 10 seconds for #1
Jun 16 15:36:54 d1 pluto[27759]: | next event EVENT_v1_RETRANSMIT in 10 seconds for #1
Jun 16 15:36:54 d1 pluto[27759]: |
Jun 16 15:36:54 d1 pluto[27759]: | *received 356 bytes from 10.0.12.2:500 on eth1 (port=500)
Jun 16 15:36:54 d1 pluto[27759]: | processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
Jun 16 15:36:54 d1 pluto[27759]: | ICOOKIE: 20 99 a2 35 d5 da 79 ce
Jun 16 15:36:54 d1 pluto[27759]: | RCOOKIE: fe 19 ee 98 16 6c 12 39
Jun 16 15:36:54 d1 pluto[27759]: | state hash entry 24
Jun 16 15:36:54 d1 pluto[27759]: | v1 peer and cookies match on #1, provided msgid 00000000 vs 00000000
Jun 16 15:36:54 d1 pluto[27759]: | v1 state object #1 found, in STATE_MAIN_R1
Jun 16 15:36:54 d1 pluto[27759]: | processing connection client/2x0[1] 10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | checking NAT-t: enabled and RFC 3947 (NAT-Traversal)
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: NAT-Traversal: Result using RFC 3947 (NAT-Traversal) sender port 500: no NAT detected
Jun 16 15:36:54 d1 pluto[27759]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Jun 16 15:36:54 d1 pluto[27759]: | event added after event EVENT_v1_RETRANSMIT for #1
Jun 16 15:36:54 d1 pluto[27759]: | crypto helper -1 doing build_kenonce; request ID 0
Jun 16 15:36:54 d1 pluto[27759]: | main inI2_outR2: calculated ke+nonce, sending R2
Jun 16 15:36:54 d1 pluto[27759]: | processing connection client/2x0[1] 10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | no IKE message padding required
Jun 16 15:36:54 d1 pluto[27759]: | main inI2_outR2: starting async DH calculation (group=14)
Jun 16 15:36:54 d1 pluto[27759]: | started looking for secret for 10.0.11.2->10.0.12.2 of kind PPK_PSK
Jun 16 15:36:54 d1 pluto[27759]: | actually looking for secret for 10.0.11.2->10.0.12.2 of kind PPK_PSK
Jun 16 15:36:54 d1 pluto[27759]: | line 1: key type PPK_PSK(10.0.11.2) to type PPK_PSK
Jun 16 15:36:54 d1 pluto[27759]: | 1: compared key (none) to 10.0.11.2 / 10.0.12.2 -> 2
Jun 16 15:36:54 d1 pluto[27759]: | 2: compared key (none) to 10.0.11.2 / 10.0.12.2 -> 2
Jun 16 15:36:54 d1 pluto[27759]: | line 1: match=2
Jun 16 15:36:54 d1 pluto[27759]: | best_match 0>2 best=0xb7838e70 (line=1)
Jun 16 15:36:54 d1 pluto[27759]: | line 2: key type PPK_PSK(10.0.11.2) to type PPK_RSA
Jun 16 15:36:54 d1 pluto[27759]: | concluding with best_match=2 best=0xb7838e70 (lineno=1)
Jun 16 15:36:54 d1 pluto[27759]: | parent1 type: 2 group: 14 len: 2672
Jun 16 15:36:54 d1 pluto[27759]: | crypto helper -1 doing compute dh+iv (V1 Phase 1); request ID 0
Jun 16 15:36:54 d1 pluto[27759]: | main inI2_outR2: calculated DH finished
Jun 16 15:36:54 d1 pluto[27759]: | processing connection client/2x0[1] 10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | started dh_secretiv, returned: stf=STF_INLINE
Jun 16 15:36:54 d1 pluto[27759]: | complete state transition with STF_OK
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
Jun 16 15:36:54 d1 pluto[27759]: | deleting event for #1
Jun 16 15:36:54 d1 pluto[27759]: | sending reply packet to 10.0.12.2:500 (from port 500)
Jun 16 15:36:54 d1 pluto[27759]: | sending 356 bytes for STATE_MAIN_R1 through eth1:500 to 10.0.12.2:500 (using #1)
Jun 16 15:36:54 d1 pluto[27759]: | inserting event EVENT_v1_RETRANSMIT, timeout in 10 seconds for #1
Jun 16 15:36:54 d1 pluto[27759]: | event added at head of queue
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: STATE_MAIN_R2: sent MR2, expecting MI3
Jun 16 15:36:54 d1 pluto[27759]: | modecfg pull: noquirk policy:pull not-client
Jun 16 15:36:54 d1 pluto[27759]: | phase 1 is done, looking for phase 2 to unpend
Jun 16 15:36:54 d1 pluto[27759]: | complete state transition with STF_INLINE
Jun 16 15:36:54 d1 pluto[27759]: | * processed 0 messages from cryptographic helpers
Jun 16 15:36:54 d1 pluto[27759]: | next event EVENT_v1_RETRANSMIT in 10 seconds for #1
Jun 16 15:36:54 d1 pluto[27759]: | next event EVENT_v1_RETRANSMIT in 10 seconds for #1
Jun 16 15:36:54 d1 pluto[27759]: |
Jun 16 15:36:54 d1 pluto[27759]: | *received 76 bytes from 10.0.12.2:500 on eth1 (port=500)
Jun 16 15:36:54 d1 pluto[27759]: | processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
Jun 16 15:36:54 d1 pluto[27759]: | ICOOKIE: 20 99 a2 35 d5 da 79 ce
Jun 16 15:36:54 d1 pluto[27759]: | RCOOKIE: fe 19 ee 98 16 6c 12 39
Jun 16 15:36:54 d1 pluto[27759]: | state hash entry 24
Jun 16 15:36:54 d1 pluto[27759]: | v1 peer and cookies match on #1, provided msgid 00000000 vs 00000000
Jun 16 15:36:54 d1 pluto[27759]: | v1 state object #1 found, in STATE_MAIN_R2
Jun 16 15:36:54 d1 pluto[27759]: | processing connection client/2x0[1] 10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: Main mode peer ID is ID_IPV4_ADDR: '10.0.12.2'
Jun 16 15:36:54 d1 pluto[27759]: | refine_connection: starting with client/2x0
Jun 16 15:36:54 d1 pluto[27759]: | match_id a=10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | b=10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | results matched
Jun 16 15:36:54 d1 pluto[27759]: | trusted_ca called with a=(empty) b=(empty)
Jun 16 15:36:54 d1 pluto[27759]: | refine_connection: checking client/2x0 against client/2x0, best=(none) with match=1(id=1/ca=1/reqca=1)
Jun 16 15:36:54 d1 pluto[27759]: | refine_connection: checked client/2x0 against client/2x0, now for see if best
Jun 16 15:36:54 d1 pluto[27759]: | started looking for secret for 10.0.11.2->10.0.12.2 of kind PPK_PSK
Jun 16 15:36:54 d1 pluto[27759]: | actually looking for secret for 10.0.11.2->10.0.12.2 of kind PPK_PSK
Jun 16 15:36:54 d1 pluto[27759]: | line 1: key type PPK_PSK(10.0.11.2) to type PPK_PSK
Jun 16 15:36:54 d1 pluto[27759]: | 1: compared key (none) to 10.0.11.2 / 10.0.12.2 -> 2
Jun 16 15:36:54 d1 pluto[27759]: | 2: compared key (none) to 10.0.11.2 / 10.0.12.2 -> 2
Jun 16 15:36:54 d1 pluto[27759]: | line 1: match=2
Jun 16 15:36:54 d1 pluto[27759]: | best_match 0>2 best=0xb7838e70 (line=1)
Jun 16 15:36:54 d1 pluto[27759]: | line 2: key type PPK_PSK(10.0.11.2) to type PPK_RSA
Jun 16 15:36:54 d1 pluto[27759]: | concluding with best_match=2 best=0xb7838e70 (lineno=1)
Jun 16 15:36:54 d1 pluto[27759]: | offered CA: '%none'
Jun 16 15:36:54 d1 pluto[27759]: | thinking about whether to send my certificate:
Jun 16 15:36:54 d1 pluto[27759]: | I have RSA key: OAKLEY_PRESHARED_KEY cert.type: CERT_NONE
Jun 16 15:36:54 d1 pluto[27759]: | sendcert: CERT_ALWAYSSEND and I did not get a certificate request
Jun 16 15:36:54 d1 pluto[27759]: | so do not send cert.
Jun 16 15:36:54 d1 pluto[27759]: | I did not send a certificate because digital signatures are not being used. (PSK)
Jun 16 15:36:54 d1 pluto[27759]: | no IKE message padding required
Jun 16 15:36:54 d1 pluto[27759]: | complete state transition with STF_OK
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: transition from state STATE_MAIN_R2 to state STATE_MAIN_R3
Jun 16 15:36:54 d1 pluto[27759]: | deleting event for #1
Jun 16 15:36:54 d1 pluto[27759]: | sending reply packet to 10.0.12.2:500 (from port 500)
Jun 16 15:36:54 d1 pluto[27759]: | sending 76 bytes for STATE_MAIN_R2 through eth1:500 to 10.0.12.2:500 (using #1)
Jun 16 15:36:54 d1 pluto[27759]: | inserting event EVENT_SA_REPLACE, timeout in 3330 seconds for #1
Jun 16 15:36:54 d1 pluto[27759]: | event added after event EVENT_PENDING_PHASE2
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: STATE_MAIN_R3: sent MR3, ISAKMP SA established {auth=PRESHARED_KEY cipher=aes_128 prf=sha group=MODP2048}
Jun 16 15:36:54 d1 pluto[27759]: | modecfg pull: noquirk policy:pull not-client
Jun 16 15:36:54 d1 pluto[27759]: | phase 1 is done, looking for phase 2 to unpend
Jun 16 15:36:54 d1 pluto[27759]: | * processed 0 messages from cryptographic helpers
Jun 16 15:36:54 d1 pluto[27759]: | next event EVENT_NAT_T_KEEPALIVE in 20 seconds
Jun 16 15:36:54 d1 pluto[27759]: | next event EVENT_NAT_T_KEEPALIVE in 20 seconds
Jun 16 15:36:54 d1 pluto[27759]: |
Jun 16 15:36:54 d1 pluto[27759]: | *received 92 bytes from 10.0.12.2:500 on eth1 (port=500)
Jun 16 15:36:54 d1 pluto[27759]: | processing version=1.0 packet with exchange type=ISAKMP_XCHG_MODE_CFG (6)
Jun 16 15:36:54 d1 pluto[27759]: | ICOOKIE: 20 99 a2 35 d5 da 79 ce
Jun 16 15:36:54 d1 pluto[27759]: | RCOOKIE: fe 19 ee 98 16 6c 12 39
Jun 16 15:36:54 d1 pluto[27759]: | state hash entry 24
Jun 16 15:36:54 d1 pluto[27759]: | peer and cookies match on #1, provided msgid 9953c715 vs 00000000/00000000
Jun 16 15:36:54 d1 pluto[27759]: | p15 state object not found
Jun 16 15:36:54 d1 pluto[27759]: | in process_v1_packet:1297 No appropriate Mode Config state yet.See if we have a Main Mode state
Jun 16 15:36:54 d1 pluto[27759]: | ICOOKIE: 20 99 a2 35 d5 da 79 ce
Jun 16 15:36:54 d1 pluto[27759]: | RCOOKIE: fe 19 ee 98 16 6c 12 39
Jun 16 15:36:54 d1 pluto[27759]: | state hash entry 24
Jun 16 15:36:54 d1 pluto[27759]: | peer and cookies match on #1, provided msgid 00000000 vs 00000000/00000000
Jun 16 15:36:54 d1 pluto[27759]: | p15 state object #1 found, in STATE_MAIN_R3
Jun 16 15:36:54 d1 pluto[27759]: | processing connection client/2x0[1] 10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | processing received isakmp_xchg_type ISAKMP_XCHG_MODE_CFG.
Jun 16 15:36:54 d1 pluto[27759]: | this is a modecfgserver
Jun 16 15:36:54 d1 pluto[27759]: | call init_phase2_iv
Jun 16 15:36:54 d1 pluto[27759]: | set from_state to STATE_MAIN_R3 this is modecfgserver and IS_PHASE1() is TRUE
Jun 16 15:36:54 d1 pluto[27759]: | arrived in modecfg_inR0
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: Unsupported modecfg long attribute MODECFG_BANNER received.
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: Unsupported modecfg long attribute MODECFG_DOMAIN received.
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: Unsupported modecfg long attribute CISCO_SPLIT_INC received.
Jun 16 15:36:54 d1 pluto[27759]: | no IKE message padding required
Jun 16 15:36:54 d1 pluto[27759]: | no IKE message padding required
Jun 16 15:36:54 d1 pluto[27759]: | no IKE message padding required
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: modecfg_inR0(STF_OK)
Jun 16 15:36:54 d1 pluto[27759]: | complete state transition with STF_OK
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: transition from state STATE_MODE_CFG_R0 to state STATE_MODE_CFG_R1
Jun 16 15:36:54 d1 pluto[27759]: | deleting event for #1
Jun 16 15:36:54 d1 pluto[27759]: | sending reply packet to 10.0.12.2:500 (from port 500)
Jun 16 15:36:54 d1 pluto[27759]: | sending 76 bytes for STATE_MODE_CFG_R0 through eth1:500 to 10.0.12.2:500 (using #1)
Jun 16 15:36:54 d1 pluto[27759]: | inserting event EVENT_SA_REPLACE, timeout in 3330 seconds for #1
Jun 16 15:36:54 d1 pluto[27759]: | event added after event EVENT_PENDING_PHASE2
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: STATE_MODE_CFG_R1: ModeCfg Set sent, expecting Ack
Jun 16 15:36:54 d1 pluto[27759]: | modecfg pull: noquirk policy:pull not-client
Jun 16 15:36:54 d1 pluto[27759]: | phase 1 is done, looking for phase 2 to unpend
Jun 16 15:36:54 d1 pluto[27759]: | * processed 0 messages from cryptographic helpers
Jun 16 15:36:54 d1 pluto[27759]: | next event EVENT_NAT_T_KEEPALIVE in 20 seconds
Jun 16 15:36:54 d1 pluto[27759]: | next event EVENT_NAT_T_KEEPALIVE in 20 seconds
Jun 16 15:36:54 d1 pluto[27759]: |
Jun 16 15:36:54 d1 pluto[27759]: | *received 508 bytes from 10.0.12.2:500 on eth1 (port=500)
Jun 16 15:36:54 d1 pluto[27759]: | processing version=1.0 packet with exchange type=ISAKMP_XCHG_QUICK (32)
Jun 16 15:36:54 d1 pluto[27759]: | ICOOKIE: 20 99 a2 35 d5 da 79 ce
Jun 16 15:36:54 d1 pluto[27759]: | RCOOKIE: fe 19 ee 98 16 6c 12 39
Jun 16 15:36:54 d1 pluto[27759]: | state hash entry 24
Jun 16 15:36:54 d1 pluto[27759]: | v1 peer and cookies match on #1, provided msgid ae9f1834 vs 00000000
Jun 16 15:36:54 d1 pluto[27759]: | v1 state object not found
Jun 16 15:36:54 d1 pluto[27759]: | ICOOKIE: 20 99 a2 35 d5 da 79 ce
Jun 16 15:36:54 d1 pluto[27759]: | RCOOKIE: fe 19 ee 98 16 6c 12 39
Jun 16 15:36:54 d1 pluto[27759]: | state hash entry 24
Jun 16 15:36:54 d1 pluto[27759]: | v1 peer and cookies match on #1, provided msgid 00000000 vs 00000000
Jun 16 15:36:54 d1 pluto[27759]: | v1 state object #1 found, in STATE_MODE_CFG_R1
Jun 16 15:36:54 d1 pluto[27759]: | processing connection client/2x0[1] 10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | peer client is 192.168.12.1
Jun 16 15:36:54 d1 pluto[27759]: | peer client protocol/port is 0/0
Jun 16 15:36:54 d1 pluto[27759]: | our client is subnet 192.168.11.0/24
Jun 16 15:36:54 d1 pluto[27759]: | our client protocol/port is 0/0
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: the peer proposed: 192.168.11.0/24:0/0 -> 192.168.12.1/32:0/0
Jun 16 15:36:54 d1 pluto[27759]: | find_client_connection starting with client/2x0
Jun 16 15:36:54 d1 pluto[27759]: | looking for 192.168.11.0/24:0/0 -> 192.168.12.1/32:0/0
Jun 16 15:36:54 d1 pluto[27759]: | concrete checking against sr#0 192.168.111.0/24 -> 192.168.13.100/32
Jun 16 15:36:54 d1 pluto[27759]: | match_id a=10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | b=10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | results matched
Jun 16 15:36:54 d1 pluto[27759]: | trusted_ca called with a=(empty) b=(empty)
Jun 16 15:36:54 d1 pluto[27759]: | fc_try trying client/2x0:192.168.11.0/24:0/0 -> 192.168.12.1/32:0/0 vs client/2x0:192.168.111.0/24:0/0 -> 192.168.13.100/32:0/0
Jun 16 15:36:54 d1 pluto[27759]: | our client(192.168.111.0/24) not in our_net (192.168.11.0/24)
Jun 16 15:36:54 d1 pluto[27759]: | fc_try concluding with none [0]
Jun 16 15:36:54 d1 pluto[27759]: | fc_try client/2x0 gives none
Jun 16 15:36:54 d1 pluto[27759]: | find_host_pair: comparing to 10.0.11.2:500 10.0.12.2:500
Jun 16 15:36:54 d1 pluto[27759]: | find_host_pair: comparing to 10.0.11.2:500 0.0.0.0:500
Jun 16 15:36:54 d1 pluto[27759]: | checking hostpair 192.168.111.0/24 -> 192.168.13.100/32 is found
Jun 16 15:36:54 d1 pluto[27759]: | match_id a=10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | b=(none)
Jun 16 15:36:54 d1 pluto[27759]: | results matched
Jun 16 15:36:54 d1 pluto[27759]: | trusted_ca called with a=(empty) b=(empty)
Jun 16 15:36:54 d1 pluto[27759]: | fc_try trying client/2x0:192.168.11.0/24:0/0 -> 192.168.12.1/32:0/0 vs client/2x0:192.168.111.0/24:0/0 -> 192.168.13.100/32:0/0
Jun 16 15:36:54 d1 pluto[27759]: | our client(192.168.111.0/24) not in our_net (192.168.11.0/24)
Jun 16 15:36:54 d1 pluto[27759]: | match_id a=10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | b=(none)
Jun 16 15:36:54 d1 pluto[27759]: | results matched
Jun 16 15:36:54 d1 pluto[27759]: | trusted_ca called with a=(empty) b=(empty)
Jun 16 15:36:54 d1 pluto[27759]: | fc_try trying client/2x0:192.168.11.0/24:0/0 -> 192.168.12.1/32:0/0 vs client/1x0:192.168.11.0/24:0/0 -> 192.168.13.100/32:0/0
Jun 16 15:36:54 d1 pluto[27759]: | their client(192.168.13.100/32) not in same peer_net (192.168.12.1/32)
Jun 16 15:36:54 d1 pluto[27759]: | fc_try concluding with none [0]
Jun 16 15:36:54 d1 pluto[27759]: | concluding with d = none
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: cannot respond to IPsec SA request because no connection is known for 192.168.11.0/24===10.0.11.2[MS+S=C]...10.0.12.2[+MC+S=C]===192.168.12.1/32
Jun 16 15:36:54 d1 pluto[27759]: | complete state transition with (null)
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: sending encrypted notification INVALID_ID_INFORMATION to 10.0.12.2:500
Jun 16 15:36:54 d1 pluto[27759]: | no IKE message padding required
Jun 16 15:36:54 d1 pluto[27759]: | sending 76 bytes for notification packet through eth1:500 to 10.0.12.2:500 (using #1)
Jun 16 15:36:54 d1 pluto[27759]: | state transition function for STATE_QUICK_R0 failed: INVALID_ID_INFORMATION
Jun 16 15:36:54 d1 pluto[27759]: | * processed 0 messages from cryptographic helpers
Jun 16 15:36:54 d1 pluto[27759]: | next event EVENT_NAT_T_KEEPALIVE in 20 seconds
Jun 16 15:36:54 d1 pluto[27759]: | next event EVENT_NAT_T_KEEPALIVE in 20 seconds
Jun 16 15:36:54 d1 pluto[27759]: |
Jun 16 15:36:54 d1 pluto[27759]: | *received 508 bytes from 10.0.12.2:500 on eth1 (port=500)
Jun 16 15:36:54 d1 pluto[27759]: | processing version=1.0 packet with exchange type=ISAKMP_XCHG_QUICK (32)
Jun 16 15:36:54 d1 pluto[27759]: | ICOOKIE: 20 99 a2 35 d5 da 79 ce
Jun 16 15:36:54 d1 pluto[27759]: | RCOOKIE: fe 19 ee 98 16 6c 12 39
Jun 16 15:36:54 d1 pluto[27759]: | state hash entry 24
Jun 16 15:36:54 d1 pluto[27759]: | v1 peer and cookies match on #1, provided msgid f08e4d00 vs 00000000
Jun 16 15:36:54 d1 pluto[27759]: | v1 state object not found
Jun 16 15:36:54 d1 pluto[27759]: | ICOOKIE: 20 99 a2 35 d5 da 79 ce
Jun 16 15:36:54 d1 pluto[27759]: | RCOOKIE: fe 19 ee 98 16 6c 12 39
Jun 16 15:36:54 d1 pluto[27759]: | state hash entry 24
Jun 16 15:36:54 d1 pluto[27759]: | v1 peer and cookies match on #1, provided msgid 00000000 vs 00000000
Jun 16 15:36:54 d1 pluto[27759]: | v1 state object #1 found, in STATE_MODE_CFG_R1
Jun 16 15:36:54 d1 pluto[27759]: | processing connection client/2x0[1] 10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | peer client is 192.168.13.100
Jun 16 15:36:54 d1 pluto[27759]: | peer client protocol/port is 0/0
Jun 16 15:36:54 d1 pluto[27759]: | our client is subnet 192.168.111.0/24
Jun 16 15:36:54 d1 pluto[27759]: | our client protocol/port is 0/0
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: the peer proposed: 192.168.111.0/24:0/0 -> 192.168.13.100/32:0/0
Jun 16 15:36:54 d1 pluto[27759]: | find_client_connection starting with client/2x0
Jun 16 15:36:54 d1 pluto[27759]: | looking for 192.168.111.0/24:0/0 -> 192.168.13.100/32:0/0
Jun 16 15:36:54 d1 pluto[27759]: | concrete checking against sr#0 192.168.111.0/24 -> 192.168.13.100/32
Jun 16 15:36:54 d1 pluto[27759]: | match_id a=10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | b=10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | results matched
Jun 16 15:36:54 d1 pluto[27759]: | trusted_ca called with a=(empty) b=(empty)
Jun 16 15:36:54 d1 pluto[27759]: | fc_try trying client/2x0:192.168.111.0/24:0/0 -> 192.168.13.100/32:0/0 vs client/2x0:192.168.111.0/24:0/0 -> 192.168.13.100/32:0/0
Jun 16 15:36:54 d1 pluto[27759]: | fc_try concluding with client/2x0 [128]
Jun 16 15:36:54 d1 pluto[27759]: | fc_try client/2x0 gives client/2x0
Jun 16 15:36:54 d1 pluto[27759]: | concluding with d = client/2x0
Jun 16 15:36:54 d1 pluto[27759]: | client wildcard: no port wildcard: no virtual: no
Jun 16 15:36:54 d1 pluto[27759]: | duplicating state object #1
Jun 16 15:36:54 d1 pluto[27759]: | creating state object #2 at 0xb7865848
Jun 16 15:36:54 d1 pluto[27759]: | processing connection client/2x0[1] 10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | ICOOKIE: 20 99 a2 35 d5 da 79 ce
Jun 16 15:36:54 d1 pluto[27759]: | RCOOKIE: fe 19 ee 98 16 6c 12 39
Jun 16 15:36:54 d1 pluto[27759]: | state hash entry 24
Jun 16 15:36:54 d1 pluto[27759]: | inserting state object #2
Jun 16 15:36:54 d1 pluto[27759]: | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #2
Jun 16 15:36:54 d1 pluto[27759]: | event added at head of queue
Jun 16 15:36:54 d1 pluto[27759]: | crypto helper -1 doing build_kenonce; request ID 0
Jun 16 15:36:54 d1 pluto[27759]: | quick inI1_outR1: calculated ke+nonce, calculating DH
Jun 16 15:36:54 d1 pluto[27759]: | processing connection client/2x0[1] 10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | started looking for secret for 10.0.11.2->10.0.12.2 of kind PPK_PSK
Jun 16 15:36:54 d1 pluto[27759]: | actually looking for secret for 10.0.11.2->10.0.12.2 of kind PPK_PSK
Jun 16 15:36:54 d1 pluto[27759]: | line 1: key type PPK_PSK(10.0.11.2) to type PPK_PSK
Jun 16 15:36:54 d1 pluto[27759]: | 1: compared key (none) to 10.0.11.2 / 10.0.12.2 -> 2
Jun 16 15:36:54 d1 pluto[27759]: | 2: compared key (none) to 10.0.11.2 / 10.0.12.2 -> 2
Jun 16 15:36:54 d1 pluto[27759]: | line 1: match=2
Jun 16 15:36:54 d1 pluto[27759]: | best_match 0>2 best=0xb7838e70 (line=1)
Jun 16 15:36:54 d1 pluto[27759]: | line 2: key type PPK_PSK(10.0.11.2) to type PPK_RSA
Jun 16 15:36:54 d1 pluto[27759]: | concluding with best_match=2 best=0xb7838e70 (lineno=1)
Jun 16 15:36:54 d1 pluto[27759]: | crypto helper -1 doing compute dh (V1 Phase 2 PFS); request ID 0
Jun 16 15:36:54 d1 pluto[27759]: | quick inI1_outR1: calculated DH, sending R1
Jun 16 15:36:54 d1 pluto[27759]: | processing connection client/2x0[1] 10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | generate SPI: 38 0a 4f eb
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #2: responding to Quick Mode proposal {msgid:004d8ef0}
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #2: us: 192.168.111.0/24===10.0.11.2[MS+S=C]
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #2: them: 10.0.12.2[+MC+S=C]===192.168.13.100/32
Jun 16 15:36:54 d1 pluto[27759]: | route owner of "client/2x0"[1] 10.0.12.2 unrouted: NULL
Jun 16 15:36:54 d1 pluto[27759]: | install_inbound_ipsec_sa() checking if we can route
Jun 16 15:36:54 d1 pluto[27759]: | route owner of "client/2x0"[1] 10.0.12.2 unrouted: NULL; eroute owner: NULL
Jun 16 15:36:54 d1 pluto[27759]: | could_route called for client/2x0 (kind=CK_INSTANCE)
Jun 16 15:36:54 d1 pluto[27759]: | routing is easy, or has resolvable near-conflict
Jun 16 15:36:54 d1 pluto[27759]: | checking if this is a replacement state
Jun 16 15:36:54 d1 pluto[27759]: | st=0xb7865848 ost=(nil) st->serialno=#2 ost->serialno=#0
Jun 16 15:36:54 d1 pluto[27759]: | installing outgoing SA now as refhim=0
Jun 16 15:36:54 d1 pluto[27759]: | outgoing SA has refhim=1
Jun 16 15:36:54 d1 pluto[27759]: | add inbound eroute 192.168.13.100/32:0 --0-> 192.168.111.0/24:0 => tun.1002 at 10.0.11.2 (raw_eroute)
Jun 16 15:36:54 d1 pluto[27759]: | raw_eroute result=1
Jun 16 15:36:54 d1 pluto[27759]: | no IKE message padding required
Jun 16 15:36:54 d1 pluto[27759]: | finished processing quick inI1
Jun 16 15:36:54 d1 pluto[27759]: | complete state transition with STF_OK
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #2: transition from state STATE_QUICK_R0 to state STATE_QUICK_R1
Jun 16 15:36:54 d1 pluto[27759]: | deleting event for #2
Jun 16 15:36:54 d1 pluto[27759]: | sending reply packet to 10.0.12.2:500 (from port 500)
Jun 16 15:36:54 d1 pluto[27759]: | sending 428 bytes for STATE_QUICK_R0 through eth1:500 to 10.0.12.2:500 (using #2)
Jun 16 15:36:54 d1 pluto[27759]: | inserting event EVENT_v1_RETRANSMIT, timeout in 10 seconds for #2
Jun 16 15:36:54 d1 pluto[27759]: | event added at head of queue
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #2: STATE_QUICK_R1: sent QR1, inbound IPsec SA installed, expecting QI2
Jun 16 15:36:54 d1 pluto[27759]: | modecfg pull: noquirk policy:pull not-client
Jun 16 15:36:54 d1 pluto[27759]: | phase 1 is done, looking for phase 2 to unpend
Jun 16 15:36:54 d1 pluto[27759]: | complete state transition with STF_INLINE
Jun 16 15:36:54 d1 pluto[27759]: | * processed 0 messages from cryptographic helpers
Jun 16 15:36:54 d1 pluto[27759]: | next event EVENT_v1_RETRANSMIT in 10 seconds for #2
Jun 16 15:36:54 d1 pluto[27759]: | next event EVENT_v1_RETRANSMIT in 10 seconds for #2
Jun 16 15:36:54 d1 pluto[27759]: |
Jun 16 15:36:54 d1 pluto[27759]: | *received 60 bytes from 10.0.12.2:500 on eth1 (port=500)
Jun 16 15:36:54 d1 pluto[27759]: | processing version=1.0 packet with exchange type=ISAKMP_XCHG_QUICK (32)
Jun 16 15:36:54 d1 pluto[27759]: | ICOOKIE: 20 99 a2 35 d5 da 79 ce
Jun 16 15:36:54 d1 pluto[27759]: | RCOOKIE: fe 19 ee 98 16 6c 12 39
Jun 16 15:36:54 d1 pluto[27759]: | state hash entry 24
Jun 16 15:36:54 d1 pluto[27759]: | v1 peer and cookies match on #2, provided msgid f08e4d00 vs f08e4d00
Jun 16 15:36:54 d1 pluto[27759]: | v1 state object #2 found, in STATE_QUICK_R1
Jun 16 15:36:54 d1 pluto[27759]: | processing connection client/2x0[1] 10.0.12.2
Jun 16 15:36:54 d1 pluto[27759]: | install_ipsec_sa() for #2: outbound only
Jun 16 15:36:54 d1 pluto[27759]: | route owner of "client/2x0"[1] 10.0.12.2 unrouted: NULL; eroute owner: NULL
Jun 16 15:36:54 d1 pluto[27759]: | could_route called for client/2x0 (kind=CK_INSTANCE)
Jun 16 15:36:54 d1 pluto[27759]: | sr for #2: unrouted
Jun 16 15:36:54 d1 pluto[27759]: | route owner of "client/2x0"[1] 10.0.12.2 unrouted: NULL; eroute owner: NULL
Jun 16 15:36:54 d1 pluto[27759]: | route_and_eroute with c: client/2x0 (next: none) ero:null esr:{(nil)} ro:null rosr:{(nil)} and state: 2
Jun 16 15:36:54 d1 pluto[27759]: | eroute_connection add eroute 192.168.111.0/24:0 --0-> 192.168.13.100/32:0 => tun.1001 at 10.0.12.2 (raw_eroute)
Jun 16 15:36:54 d1 pluto[27759]: | raw_eroute result=1
Jun 16 15:36:54 d1 pluto[27759]: | command executing up-client
Jun 16 15:36:54 d1 pluto[27759]: | executing up-client: 2>&1 PLUTO_VERB='up-client' PLUTO_VERSION='2.0' PLUTO_CONNECTION='client/2x0' PLUTO_INTERFACE='ipsec0' PLUTO_NEXT_HOP='10.0.11.1' PLUTO_ME='10.0.11.2' PLUTO_MY_ID='10.0.11.2' PLUTO_MY_CLIENT='192.168.111.0/24' PLUTO_MY_CLIENT_NET='192.168.111.0' PLUTO_MY_CLIENT_MASK='255.255.255.0' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16388' PLUTO_PEER='10.0.12.2' PLUTO_PEER_ID='10.0.12.2' PLUTO_PEER_CLIENT='192.168.13.100/32' PLUTO_PEER_CLIENT_NET='192.168.13.100' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='klips' PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW' PLUTO_CONN_ADDRFAMILY='ipv4' XAUTH_FAILED=0 PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO='' PLUTO_PEER_BANNER='' ipsec _updown
Jun 16 15:36:54 d1 pluto[27759]: | popen cmd is 844 chars long
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 0):2>&1 PLUTO_VERB='up-client' PLUTO_VERSION='2.0' PLUTO_CONNECTION='client/2x0' PL:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 80):UTO_INTERFACE='ipsec0' PLUTO_NEXT_HOP='10.0.11.1' PLUTO_ME='10.0.11.2' PLUTO_MY_:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 160):ID='10.0.11.2' PLUTO_MY_CLIENT='192.168.111.0/24' PLUTO_MY_CLIENT_NET='192.168.1:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 240):11.0' PLUTO_MY_CLIENT_MASK='255.255.255.0' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL=':
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 320):0' PLUTO_SA_REQID='16388' PLUTO_PEER='10.0.12.2' PLUTO_PEER_ID='10.0.12.2' PLUTO:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 400):_PEER_CLIENT='192.168.13.100/32' PLUTO_PEER_CLIENT_NET='192.168.13.100' PLUTO_PE:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 480):ER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLU:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 560):TO_PEER_CA='' PLUTO_STACK='klips' PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+MO:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 640):DECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW' PLUTO_CONN_ADDRFAMILY='ipv4' :
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 720):XAUTH_FAILED=0 PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAI:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 800):N_INFO='' PLUTO_PEER_BANNER='' ipsec _updown:
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #2: up-client output: /usr/libexec/ipsec/_updown.klips: dorule "ip rule delete from 192.168.111.0/24 to 192.168.13.100/32 table main prio 1" failed (RTNETLINK answers: No such file or directory)
Jun 16 15:36:54 d1 pluto[27759]: | route_and_eroute: firewall_notified: true
Jun 16 15:36:54 d1 pluto[27759]: | command executing prepare-client
Jun 16 15:36:54 d1 pluto[27759]: | executing prepare-client: 2>&1 PLUTO_VERB='prepare-client' PLUTO_VERSION='2.0' PLUTO_CONNECTION='client/2x0' PLUTO_INTERFACE='ipsec0' PLUTO_NEXT_HOP='10.0.11.1' PLUTO_ME='10.0.11.2' PLUTO_MY_ID='10.0.11.2' PLUTO_MY_CLIENT='192.168.111.0/24' PLUTO_MY_CLIENT_NET='192.168.111.0' PLUTO_MY_CLIENT_MASK='255.255.255.0' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16388' PLUTO_PEER='10.0.12.2' PLUTO_PEER_ID='10.0.12.2' PLUTO_PEER_CLIENT='192.168.13.100/32' PLUTO_PEER_CLIENT_NET='192.168.13.100' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='klips' PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW' PLUTO_CONN_ADDRFAMILY='ipv4' XAUTH_FAILED=0 PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO='' PLUTO_PEER_BANNER='' ipsec _updown
Jun 16 15:36:54 d1 pluto[27759]: | popen cmd is 849 chars long
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 0):2>&1 PLUTO_VERB='prepare-client' PLUTO_VERSION='2.0' PLUTO_CONNECTION='client/2x:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 80):0' PLUTO_INTERFACE='ipsec0' PLUTO_NEXT_HOP='10.0.11.1' PLUTO_ME='10.0.11.2' PLUT:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 160):O_MY_ID='10.0.11.2' PLUTO_MY_CLIENT='192.168.111.0/24' PLUTO_MY_CLIENT_NET='192.:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 240):168.111.0' PLUTO_MY_CLIENT_MASK='255.255.255.0' PLUTO_MY_PORT='0' PLUTO_MY_PROTO:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 320):COL='0' PLUTO_SA_REQID='16388' PLUTO_PEER='10.0.12.2' PLUTO_PEER_ID='10.0.12.2' :
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 400):PLUTO_PEER_CLIENT='192.168.13.100/32' PLUTO_PEER_CLIENT_NET='192.168.13.100' PLU:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 480):TO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 560):' PLUTO_PEER_CA='' PLUTO_STACK='klips' PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+P:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 640):FS+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW' PLUTO_CONN_ADDRFAMILY='i:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 720):pv4' XAUTH_FAILED=0 PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 800):DOMAIN_INFO='' PLUTO_PEER_BANNER='' ipsec _updown:
Jun 16 15:36:54 d1 pluto[27759]: | command executing route-client
Jun 16 15:36:54 d1 pluto[27759]: | executing route-client: 2>&1 PLUTO_VERB='route-client' PLUTO_VERSION='2.0' PLUTO_CONNECTION='client/2x0' PLUTO_INTERFACE='ipsec0' PLUTO_NEXT_HOP='10.0.11.1' PLUTO_ME='10.0.11.2' PLUTO_MY_ID='10.0.11.2' PLUTO_MY_CLIENT='192.168.111.0/24' PLUTO_MY_CLIENT_NET='192.168.111.0' PLUTO_MY_CLIENT_MASK='255.255.255.0' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCOL='0' PLUTO_SA_REQID='16388' PLUTO_PEER='10.0.12.2' PLUTO_PEER_ID='10.0.12.2' PLUTO_PEER_CLIENT='192.168.13.100/32' PLUTO_PEER_CLIENT_NET='192.168.13.100' PLUTO_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' PLUTO_PEER_CA='' PLUTO_STACK='klips' PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW' PLUTO_CONN_ADDRFAMILY='ipv4' XAUTH_FAILED=0 PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DOMAIN_INFO='' PLUTO_PEER_BANNER='' ipsec _updown
Jun 16 15:36:54 d1 pluto[27759]: | popen cmd is 847 chars long
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 0):2>&1 PLUTO_VERB='route-client' PLUTO_VERSION='2.0' PLUTO_CONNECTION='client/2x0':
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 80): PLUTO_INTERFACE='ipsec0' PLUTO_NEXT_HOP='10.0.11.1' PLUTO_ME='10.0.11.2' PLUTO_:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 160):MY_ID='10.0.11.2' PLUTO_MY_CLIENT='192.168.111.0/24' PLUTO_MY_CLIENT_NET='192.16:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 240):8.111.0' PLUTO_MY_CLIENT_MASK='255.255.255.0' PLUTO_MY_PORT='0' PLUTO_MY_PROTOCO:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 320):L='0' PLUTO_SA_REQID='16388' PLUTO_PEER='10.0.12.2' PLUTO_PEER_ID='10.0.12.2' PL:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 400):UTO_PEER_CLIENT='192.168.13.100/32' PLUTO_PEER_CLIENT_NET='192.168.13.100' PLUTO:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 480):_PEER_CLIENT_MASK='255.255.255.255' PLUTO_PEER_PORT='0' PLUTO_PEER_PROTOCOL='0' :
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 560):PLUTO_PEER_CA='' PLUTO_STACK='klips' PLUTO_CONN_POLICY='PSK+ENCRYPT+TUNNEL+PFS:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 640):+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW' PLUTO_CONN_ADDRFAMILY='ipv:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 720):4' XAUTH_FAILED=0 PLUTO_IS_PEER_CISCO='0' PLUTO_PEER_DNS_INFO='' PLUTO_PEER_DO:
Jun 16 15:36:54 d1 pluto[27759]: | cmd( 800):MAIN_INFO='' PLUTO_PEER_BANNER='' ipsec _updown:
Jun 16 15:36:54 d1 pluto[27759]: | route_and_eroute: instance "client/2x0"[1] 10.0.12.2, setting eroute_owner {spd=0xb783d0b0,sr=0xb783d0b0} to #2 (was #0) (newest_ipsec_sa=#0)
Jun 16 15:36:54 d1 pluto[27759]: | inI2: instance client/2x0[1], setting newest_ipsec_sa to #2 (was #0) (spd.eroute=#2)
Jun 16 15:36:54 d1 pluto[27759]: | complete state transition with STF_OK
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #2: transition from state STATE_QUICK_R1 to state STATE_QUICK_R2
Jun 16 15:36:54 d1 pluto[27759]: | deleting event for #2
Jun 16 15:36:54 d1 pluto[27759]: | inserting event EVENT_SA_REPLACE, timeout in 28530 seconds for #2
Jun 16 15:36:54 d1 pluto[27759]: | event added after event EVENT_REINIT_SECRET
Jun 16 15:36:54 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #2: STATE_QUICK_R2: IPsec SA established tunnel mode {ESP=>0xf3119658 <0x380a4feb xfrm=AES_128-HMAC_SHA1 NATOA=none NATD=none DPD=passive}
Jun 16 15:36:54 d1 pluto[27759]: | modecfg pull: noquirk policy:pull not-client
Jun 16 15:36:54 d1 pluto[27759]: | phase 1 is done, looking for phase 2 to unpend
Jun 16 15:36:54 d1 pluto[27759]: | * processed 0 messages from cryptographic helpers
Jun 16 15:36:54 d1 pluto[27759]: | next event EVENT_NAT_T_KEEPALIVE in 20 seconds
Jun 16 15:36:54 d1 pluto[27759]: | next event EVENT_NAT_T_KEEPALIVE in 20 seconds
Jun 16 15:37:04 d1 pluto[27759]: |
Jun 16 15:37:04 d1 pluto[27759]: | *received 508 bytes from 10.0.12.2:500 on eth1 (port=500)
Jun 16 15:37:04 d1 pluto[27759]: | processing version=1.0 packet with exchange type=ISAKMP_XCHG_QUICK (32)
Jun 16 15:37:04 d1 pluto[27759]: | ICOOKIE: 20 99 a2 35 d5 da 79 ce
Jun 16 15:37:04 d1 pluto[27759]: | RCOOKIE: fe 19 ee 98 16 6c 12 39
Jun 16 15:37:04 d1 pluto[27759]: | state hash entry 24
Jun 16 15:37:04 d1 pluto[27759]: | v1 peer and cookies match on #2, provided msgid ae9f1834 vs f08e4d00
Jun 16 15:37:04 d1 pluto[27759]: | v1 peer and cookies match on #1, provided msgid ae9f1834 vs 00000000
Jun 16 15:37:04 d1 pluto[27759]: | v1 state object not found
Jun 16 15:37:04 d1 pluto[27759]: | ICOOKIE: 20 99 a2 35 d5 da 79 ce
Jun 16 15:37:04 d1 pluto[27759]: | RCOOKIE: fe 19 ee 98 16 6c 12 39
Jun 16 15:37:04 d1 pluto[27759]: | state hash entry 24
Jun 16 15:37:04 d1 pluto[27759]: | v1 peer and cookies match on #2, provided msgid 00000000 vs f08e4d00
Jun 16 15:37:04 d1 pluto[27759]: | v1 peer and cookies match on #1, provided msgid 00000000 vs 00000000
Jun 16 15:37:04 d1 pluto[27759]: | v1 state object #1 found, in STATE_MODE_CFG_R1
Jun 16 15:37:04 d1 pluto[27759]: | processing connection client/2x0[1] 10.0.12.2
Jun 16 15:37:04 d1 pluto[27759]: | peer client is 192.168.12.1
Jun 16 15:37:04 d1 pluto[27759]: | peer client protocol/port is 0/0
Jun 16 15:37:04 d1 pluto[27759]: | our client is subnet 192.168.11.0/24
Jun 16 15:37:04 d1 pluto[27759]: | our client protocol/port is 0/0
Jun 16 15:37:04 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: the peer proposed: 192.168.11.0/24:0/0 -> 192.168.12.1/32:0/0
Jun 16 15:37:04 d1 pluto[27759]: | find_client_connection starting with client/2x0
Jun 16 15:37:04 d1 pluto[27759]: | looking for 192.168.11.0/24:0/0 -> 192.168.12.1/32:0/0
Jun 16 15:37:04 d1 pluto[27759]: | concrete checking against sr#0 192.168.111.0/24 -> 192.168.13.100/32
Jun 16 15:37:04 d1 pluto[27759]: | match_id a=10.0.12.2
Jun 16 15:37:04 d1 pluto[27759]: | b=10.0.12.2
Jun 16 15:37:04 d1 pluto[27759]: | results matched
Jun 16 15:37:04 d1 pluto[27759]: | trusted_ca called with a=(empty) b=(empty)
Jun 16 15:37:04 d1 pluto[27759]: | fc_try trying client/2x0:192.168.11.0/24:0/0 -> 192.168.12.1/32:0/0 vs client/2x0:192.168.111.0/24:0/0 -> 192.168.13.100/32:0/0
Jun 16 15:37:04 d1 pluto[27759]: | our client(192.168.111.0/24) not in our_net (192.168.11.0/24)
Jun 16 15:37:04 d1 pluto[27759]: | fc_try concluding with none [0]
Jun 16 15:37:04 d1 pluto[27759]: | fc_try client/2x0 gives none
Jun 16 15:37:04 d1 pluto[27759]: | find_host_pair: comparing to 10.0.11.2:500 0.0.0.0:500
Jun 16 15:37:04 d1 pluto[27759]: | checking hostpair 192.168.111.0/24 -> 192.168.13.100/32 is found
Jun 16 15:37:04 d1 pluto[27759]: | match_id a=10.0.12.2
Jun 16 15:37:04 d1 pluto[27759]: | b=(none)
Jun 16 15:37:04 d1 pluto[27759]: | results matched
Jun 16 15:37:04 d1 pluto[27759]: | trusted_ca called with a=(empty) b=(empty)
Jun 16 15:37:04 d1 pluto[27759]: | fc_try trying client/2x0:192.168.11.0/24:0/0 -> 192.168.12.1/32:0/0 vs client/2x0:192.168.111.0/24:0/0 -> 192.168.13.100/32:0/0
Jun 16 15:37:04 d1 pluto[27759]: | our client(192.168.111.0/24) not in our_net (192.168.11.0/24)
Jun 16 15:37:04 d1 pluto[27759]: | match_id a=10.0.12.2
Jun 16 15:37:04 d1 pluto[27759]: | b=(none)
Jun 16 15:37:04 d1 pluto[27759]: | results matched
Jun 16 15:37:04 d1 pluto[27759]: | trusted_ca called with a=(empty) b=(empty)
Jun 16 15:37:04 d1 pluto[27759]: | fc_try trying client/2x0:192.168.11.0/24:0/0 -> 192.168.12.1/32:0/0 vs client/1x0:192.168.11.0/24:0/0 -> 192.168.13.100/32:0/0
Jun 16 15:37:04 d1 pluto[27759]: | their client(192.168.13.100/32) not in same peer_net (192.168.12.1/32)
Jun 16 15:37:04 d1 pluto[27759]: | fc_try concluding with none [0]
Jun 16 15:37:04 d1 pluto[27759]: | concluding with d = none
Jun 16 15:37:04 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: cannot respond to IPsec SA request because no connection is known for 192.168.11.0/24===10.0.11.2[MS+S=C]...10.0.12.2[+MC+S=C]===192.168.12.1/32
Jun 16 15:37:04 d1 pluto[27759]: | complete state transition with (null)
Jun 16 15:37:04 d1 pluto[27759]: "client/2x0"[1] 10.0.12.2 #1: sending encrypted notification INVALID_ID_INFORMATION to 10.0.12.2:500
Jun 16 15:37:04 d1 pluto[27759]: | no IKE message padding required
More information about the Swan
mailing list