[Swan-dev] ASSERTION FAILED in ikev1.c

Wolfgang Nothdurft wolfgang at linogate.de
Fri Jun 13 14:30:35 EEST 2014


With git commit 4bb0f023ffa246f29dbcc21fb231e57675a31d97 pluto crashed 
on my test connections.

ASSERTION FAILED at 
/usr/src/redhat/BUILD/libreswan-3.9/programs/pluto/ikev1.c:2290: md == NULL

see attached log.

Wolfgang
-------------- next part --------------
Jun 13 13:18:10 d1 ipsec__plutorun: Starting Pluto subsystem...
Jun 13 13:18:10 d1 pluto[2771]: Using sql format key4.db, cert9.db
Jun 13 13:18:10 d1 pluto[2771]: Initializing NSS: DB is sql:/etc/ipsec.d
Jun 13 13:18:10 d1 pluto[2771]: NSS initialized
Jun 13 13:18:10 d1 pluto[2771]: libcap-ng support [disabled]
Jun 13 13:18:10 d1 pluto[2771]: FIPS HMAC integrity support [disabled]
Jun 13 13:18:10 d1 pluto[2771]: Linux audit support [disabled]
Jun 13 13:18:10 d1 pluto[2771]: Starting Pluto (Libreswan Version 3.master-201424.git XFRM(netkey) KLIPS NSS XAUTH_PAM KLIPS_MAST) pid:2771
Jun 13 13:18:10 d1 pluto[2771]: core dump dir: /var/run/pluto
Jun 13 13:18:10 d1 pluto[2771]: secrets file: /etc/ipsec.secrets
Jun 13 13:18:10 d1 pluto[2771]: leak-detective disabled
Jun 13 13:18:10 d1 pluto[2771]: SAref support [enabled]
Jun 13 13:18:10 d1 pluto[2771]: SAbind support [enabled]
Jun 13 13:18:10 d1 pluto[2771]: NSS crypto [enabled]
Jun 13 13:18:10 d1 pluto[2771]: XAUTH PAM support [enabled]
Jun 13 13:18:10 d1 pluto[2771]:    NAT-Traversal support  [enabled]
Jun 13 13:18:10 d1 pluto[2771]: | inserting event EVENT_REINIT_SECRET, timeout in 3600 seconds
Jun 13 13:18:10 d1 pluto[2771]: | event added at head of queue
Jun 13 13:18:10 d1 pluto[2771]: | inserting event EVENT_PENDING_DDNS, timeout in 60 seconds
Jun 13 13:18:10 d1 pluto[2771]: | event added at head of queue
Jun 13 13:18:10 d1 pluto[2771]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
Jun 13 13:18:10 d1 pluto[2771]: | event added after event EVENT_PENDING_DDNS
Jun 13 13:18:10 d1 pluto[2771]: ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC_SSH: Ok (ret=0)
Jun 13 13:18:10 d1 pluto[2771]: ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC: Ok (ret=0)
Jun 13 13:18:10 d1 pluto[2771]: ike_alg_register_enc(): Activating OAKLEY_SERPENT_CBC: Ok (ret=0)
Jun 13 13:18:10 d1 pluto[2771]: ike_alg_register_enc(): Activating OAKLEY_AES_CBC: Ok (ret=0)
Jun 13 13:18:10 d1 pluto[2771]: ike_alg_register_hash(): Activating OAKLEY_SHA2_512: Ok (ret=0)
Jun 13 13:18:10 d1 pluto[2771]: ike_alg_register_hash(): Activating OAKLEY_SHA2_384: Ok (ret=0)
Jun 13 13:18:10 d1 pluto[2771]: ike_alg_register_hash(): Activating OAKLEY_SHA2_256: Ok (ret=0)
Jun 13 13:18:10 d1 pluto[2771]: no crypto helpers will be started; all cryptographic operations will be done inline
Jun 13 13:18:10 d1 pluto[2771]: Using KLIPS IPsec interface code on 2.6.32.62
Jun 13 13:18:10 d1 pluto[2771]: | inserting event EVENT_SHUNT_SCAN, timeout in 120 seconds
Jun 13 13:18:10 d1 pluto[2771]: | event added after event EVENT_PENDING_DDNS
Jun 13 13:18:10 d1 pluto[2771]: | Changed path to directory '/etc/ipsec.d/cacerts'
Jun 13 13:18:10 d1 pluto[2771]:   loading CA cert file 'server.crt' (1701 bytes)
Jun 13 13:18:10 d1 pluto[2771]: |   TRUE
Jun 13 13:18:10 d1 pluto[2771]:   loading CA cert file 'ca.crt' (2366 bytes)
Jun 13 13:18:10 d1 pluto[2771]: |   TRUE
Jun 13 13:18:10 d1 pluto[2771]: | Changing to directory '/etc/ipsec.d/crls'
Jun 13 13:18:10 d1 pluto[2771]:   discarded crl file 'server.crl', bad size 0 bytes
Jun 13 13:18:10 d1 pluto[2771]: | inserting event EVENT_LOG_DAILY, timeout in 38510 seconds
Jun 13 13:18:10 d1 pluto[2771]: | event added after event EVENT_REINIT_SECRET
Jun 13 13:18:10 d1 pluto[2771]: listening for IKE messages
Jun 13 13:18:10 d1 pluto[2771]: | Inspecting interface lo 
Jun 13 13:18:10 d1 pluto[2771]: | found lo with address 127.0.0.1
Jun 13 13:18:10 d1 pluto[2771]: | Inspecting interface eth1 
Jun 13 13:18:10 d1 pluto[2771]: | found eth1 with address 10.0.11.2
Jun 13 13:18:10 d1 pluto[2771]: | Inspecting interface eth0 
Jun 13 13:18:10 d1 pluto[2771]: | found eth0 with address 192.168.11.1
Jun 13 13:18:10 d1 pluto[2771]: | Inspecting interface eth2 
Jun 13 13:18:10 d1 pluto[2771]: | found eth2 with address 172.16.16.2
Jun 13 13:18:10 d1 pluto[2771]: | Inspecting interface eth3 
Jun 13 13:18:10 d1 pluto[2771]: | found eth3 with address 192.168.192.111
Jun 13 13:18:10 d1 pluto[2771]: | Inspecting interface ipsec0 
Jun 13 13:18:10 d1 pluto[2771]: | found ipsec0 with address 10.0.11.2
Jun 13 13:18:10 d1 pluto[2771]: | IP interface eth3 192.168.192.111 has no matching ipsec* interface -- ignored
Jun 13 13:18:10 d1 pluto[2771]: | IP interface eth2 172.16.16.2 has no matching ipsec* interface -- ignored
Jun 13 13:18:10 d1 pluto[2771]: | IP interface eth0 192.168.11.1 has no matching ipsec* interface -- ignored
Jun 13 13:18:10 d1 pluto[2771]: adding interface ipsec0/eth1 10.0.11.2:500
Jun 13 13:18:10 d1 pluto[2771]: adding interface ipsec0/eth1 10.0.11.2:4500
Jun 13 13:18:10 d1 pluto[2771]: | IP interface lo 127.0.0.1 has no matching ipsec* interface -- ignored
Jun 13 13:18:10 d1 pluto[2771]: | could not open /proc/net/if_inet6
Jun 13 13:18:10 d1 pluto[2771]: | certs and keys locked by 'free_preshared_secrets'
Jun 13 13:18:10 d1 pluto[2771]: | certs and keys unlocked by 'free_preshard_secrets'
Jun 13 13:18:10 d1 pluto[2771]: loading secrets from "/etc/ipsec.secrets"
Jun 13 13:18:10 d1 pluto[2771]:     could not open host cert with nick name '/etc/ipsec.d/server.crt' in NSS DB
Jun 13 13:18:10 d1 pluto[2771]: "/etc/ipsec.secrets" line 2: NSS certficate not found
Jun 13 13:18:10 d1 pluto[2771]: loaded private key for keyid: PPK_RSA:AwEAAaBJJ
Jun 13 13:18:10 d1 pluto[2771]: | certs and keys locked by 'process_secret'
Jun 13 13:18:10 d1 pluto[2771]: | certs and keys unlocked by 'process_secret'
Jun 13 13:18:10 d1 pluto[2771]: loading secrets from "/etc/ipsec.d/client-0-client.psk"
Jun 13 13:18:10 d1 pluto[2771]: | Processing PSK at line 1: passed
Jun 13 13:18:10 d1 pluto[2771]: | certs and keys locked by 'process_secret'
Jun 13 13:18:10 d1 pluto[2771]: | certs and keys unlocked by 'process_secret'
Jun 13 13:18:10 d1 pluto[2771]: | next event EVENT_PENDING_DDNS in 60 seconds
Jun 13 13:18:11 d1 pluto[2773]: | calling addconn helper using execve
Jun 13 13:18:11 d1 pluto[2771]: |  
Jun 13 13:18:11 d1 pluto[2771]: | *received whack message
Jun 13 13:18:11 d1 pluto[2771]: | find_host_pair_conn (check_connection_end): 10.0.11.2:500 %any:500 -> hp:none 
Jun 13 13:18:11 d1 pluto[2771]: | Added new connection client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0 with policy PSK+ENCRYPT+TUNNEL+PFS+DONT_REKEY+XAUTH+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW
Jun 13 13:18:11 d1 pluto[2771]: | counting wild cards for (none) is 15
Jun 13 13:18:11 d1 pluto[2771]: | counting wild cards for (none) is 15
Jun 13 13:18:11 d1 pluto[2771]: | based upon policy, the connection is a template.
Jun 13 13:18:11 d1 pluto[2771]: | connect_to_host_pair: 10.0.11.2:500 0.0.0.0:500 -> hp:none 
Jun 13 13:18:11 d1 pluto[2771]: added connection description "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"
Jun 13 13:18:11 d1 pluto[2771]: | 192.168.11.0/24===10.0.11.2[MS+XS+S=C]---10.0.11.1...%any[+MC+XC+S=C]===192.168.11.100/32
Jun 13 13:18:11 d1 pluto[2771]: | ike_life: 21600s; ipsec_life: 32400s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 3; policy: PSK+ENCRYPT+TUNNEL+PFS+DONT_REKEY+XAUTH+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW
Jun 13 13:18:11 d1 pluto[2771]: | * processed 0 messages from cryptographic helpers 
Jun 13 13:18:11 d1 pluto[2771]: | next event EVENT_PENDING_DDNS in 59 seconds
Jun 13 13:18:11 d1 pluto[2771]: | next event EVENT_PENDING_DDNS in 59 seconds
Jun 13 13:18:11 d1 pluto[2771]: | next event EVENT_PENDING_DDNS in 59 seconds
Jun 13 13:18:11 d1 pluto[2771]: | reaped addconn helper child
Jun 13 13:18:30 d1 pluto[2771]: |  
Jun 13 13:18:30 d1 pluto[2771]: | *received 60 bytes from 10.0.12.2:500 on eth1 (port=500)
Jun 13 13:18:30 d1 pluto[2771]: |  processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
Jun 13 13:18:30 d1 pluto[2771]: | ICOOKIE:  5a 0f cc 31  da 43 08 8a
Jun 13 13:18:30 d1 pluto[2771]: | RCOOKIE:  2e 47 d4 6d  af 81 39 e5
Jun 13 13:18:30 d1 pluto[2771]: | state hash entry 21
Jun 13 13:18:30 d1 pluto[2771]: | v1 state object not found
Jun 13 13:18:30 d1 pluto[2771]: | ICOOKIE:  5a 0f cc 31  da 43 08 8a
Jun 13 13:18:30 d1 pluto[2771]: | RCOOKIE:  00 00 00 00  00 00 00 00
Jun 13 13:18:30 d1 pluto[2771]: | state hash entry 5
Jun 13 13:18:30 d1 pluto[2771]: | v1 state object not found
Jun 13 13:18:30 d1 pluto[2771]: packet from 10.0.12.2:500: phase 1 message is part of an unknown exchange
Jun 13 13:18:30 d1 pluto[2771]: | * processed 0 messages from cryptographic helpers 
Jun 13 13:18:30 d1 pluto[2771]: | next event EVENT_PENDING_DDNS in 41 seconds
Jun 13 13:18:30 d1 pluto[2771]: | next event EVENT_PENDING_DDNS in 41 seconds
Jun 13 13:19:10 d1 pluto[2771]: |  
Jun 13 13:19:10 d1 pluto[2771]: | *received 380 bytes from 10.0.12.2:500 on eth1 (port=500)
Jun 13 13:19:10 d1 pluto[2771]: |  processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
Jun 13 13:19:10 d1 pluto[2771]: packet from 10.0.12.2:500: received Vendor ID payload [Dead Peer Detection]
Jun 13 13:19:10 d1 pluto[2771]: packet from 10.0.12.2:500: received Vendor ID payload [FRAGMENTATION]
Jun 13 13:19:10 d1 pluto[2771]: packet from 10.0.12.2:500: received Vendor ID payload [RFC 3947]
Jun 13 13:19:10 d1 pluto[2771]: packet from 10.0.12.2:500: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03]
Jun 13 13:19:10 d1 pluto[2771]: packet from 10.0.12.2:500: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]
Jun 13 13:19:10 d1 pluto[2771]: packet from 10.0.12.2:500: ignoring Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02]
Jun 13 13:19:10 d1 pluto[2771]: packet from 10.0.12.2:500: received Vendor ID payload [XAUTH]
Jun 13 13:19:10 d1 pluto[2771]: | find_host_connection me=10.0.11.2:500 him=10.0.12.2:500 policy=none
Jun 13 13:19:10 d1 pluto[2771]: | find_host_pair: comparing to 10.0.11.2:500 0.0.0.0:500 
Jun 13 13:19:10 d1 pluto[2771]: | find_host_pair_conn (find_host_connection): 10.0.11.2:500 10.0.12.2:500 -> hp:none 
Jun 13 13:19:10 d1 pluto[2771]: | find_host_connection returns empty
Jun 13 13:19:10 d1 pluto[2771]: | find_host_connection me=10.0.11.2:500 him=%any:500 policy=PSK+XAUTH
Jun 13 13:19:10 d1 pluto[2771]: | find_host_pair: comparing to 10.0.11.2:500 0.0.0.0:500 
Jun 13 13:19:10 d1 pluto[2771]: | find_host_pair_conn (find_host_connection): 10.0.11.2:500 %any:500 -> hp:client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0 
Jun 13 13:19:10 d1 pluto[2771]: | searching for connection with policy = PSK+XAUTH
Jun 13 13:19:10 d1 pluto[2771]: | found policy = PSK+ENCRYPT+TUNNEL+PFS+DONT_REKEY+XAUTH+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW (client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0)
Jun 13 13:19:10 d1 pluto[2771]: | find_host_connection returns client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0
Jun 13 13:19:10 d1 pluto[2771]: | instantiating "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0" for initial Main Mode message received on 10.0.11.2:500
Jun 13 13:19:10 d1 pluto[2771]: | find_host_pair: comparing to 10.0.11.2:500 0.0.0.0:500 
Jun 13 13:19:10 d1 pluto[2771]: | connect_to_host_pair: 10.0.11.2:500 10.0.12.2:500 -> hp:none 
Jun 13 13:19:10 d1 pluto[2771]: | instantiated "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0" for 10.0.12.2
Jun 13 13:19:10 d1 pluto[2771]: | creating state object #1 at 0xb7805d08
Jun 13 13:19:10 d1 pluto[2771]: | processing connection client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0[1] 10.0.12.2
Jun 13 13:19:10 d1 pluto[2771]: | ICOOKIE:  eb 0a 5f 83  25 9d 91 f4
Jun 13 13:19:10 d1 pluto[2771]: | RCOOKIE:  a1 72 18 ee  58 9a 44 5c
Jun 13 13:19:10 d1 pluto[2771]: | state hash entry 23
Jun 13 13:19:10 d1 pluto[2771]: | inserting state object #1
Jun 13 13:19:10 d1 pluto[2771]: | inserting event EVENT_SO_DISCARD, timeout in 0 seconds for #1
Jun 13 13:19:10 d1 pluto[2771]: | event added at head of queue
Jun 13 13:19:10 d1 pluto[2771]: | sender checking NAT-t: enabled and 83
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: enabling possible NAT-traversal with method RFC 3947 (NAT-Traversal)
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: responding to Main Mode from unknown peer 10.0.12.2
Jun 13 13:19:10 d1 pluto[2771]: | started looking for secret for 10.0.11.2->10.0.12.2 of kind PPK_PSK
Jun 13 13:19:10 d1 pluto[2771]: | actually looking for secret for 10.0.11.2->10.0.12.2 of kind PPK_PSK
Jun 13 13:19:10 d1 pluto[2771]: | line 1: key type PPK_PSK(10.0.11.2) to type PPK_PSK 
Jun 13 13:19:10 d1 pluto[2771]: | 1: compared key (none) to 10.0.11.2 / 10.0.12.2 -> 2
Jun 13 13:19:10 d1 pluto[2771]: | 2: compared key (none) to 10.0.11.2 / 10.0.12.2 -> 2
Jun 13 13:19:10 d1 pluto[2771]: | line 1: match=2 
Jun 13 13:19:10 d1 pluto[2771]: | best_match 0>2 best=0xb7807430 (line=1)
Jun 13 13:19:10 d1 pluto[2771]: | line 2: key type PPK_PSK(10.0.11.2) to type PPK_RSA 
Jun 13 13:19:10 d1 pluto[2771]: | concluding with best_match=2 best=0xb7807430 (lineno=1)
Jun 13 13:19:10 d1 pluto[2771]: | no IKE message padding required
Jun 13 13:19:10 d1 pluto[2771]: | peer supports fragmentation
Jun 13 13:19:10 d1 pluto[2771]: | complete state transition with STF_OK
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: transition from state STATE_MAIN_R0 to state STATE_MAIN_R1
Jun 13 13:19:10 d1 pluto[2771]: | deleting event for #1
Jun 13 13:19:10 d1 pluto[2771]: | sending reply packet to 10.0.12.2:500 (from port 500)
Jun 13 13:19:10 d1 pluto[2771]: | sending 156 bytes for STATE_MAIN_R0 through eth1:500 to 10.0.12.2:500 (using #1)
Jun 13 13:19:10 d1 pluto[2771]: | inserting event EVENT_v1_RETRANSMIT, timeout in 10 seconds for #1
Jun 13 13:19:10 d1 pluto[2771]: | event added after event EVENT_PENDING_DDNS
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: STATE_MAIN_R1: sent MR1, expecting MI2
Jun 13 13:19:10 d1 pluto[2771]: | modecfg pull: noquirk policy:pull not-client
Jun 13 13:19:10 d1 pluto[2771]: | phase 1 is done, looking for phase 2 to unpend
Jun 13 13:19:10 d1 pluto[2771]: | * processed 0 messages from cryptographic helpers 
Jun 13 13:19:10 d1 pluto[2771]: | next event EVENT_PENDING_DDNS in 1 seconds
Jun 13 13:19:10 d1 pluto[2771]: | next event EVENT_PENDING_DDNS in 1 seconds
Jun 13 13:19:10 d1 pluto[2771]: |  
Jun 13 13:19:10 d1 pluto[2771]: | *received 284 bytes from 10.0.12.2:500 on eth1 (port=500)
Jun 13 13:19:10 d1 pluto[2771]: |  processing version=1.0 packet with exchange type=ISAKMP_XCHG_IDPROT (2)
Jun 13 13:19:10 d1 pluto[2771]: | ICOOKIE:  eb 0a 5f 83  25 9d 91 f4
Jun 13 13:19:10 d1 pluto[2771]: | RCOOKIE:  a1 72 18 ee  58 9a 44 5c
Jun 13 13:19:10 d1 pluto[2771]: | state hash entry 23
Jun 13 13:19:10 d1 pluto[2771]: | v1 peer and cookies match on #1, provided msgid 00000000 vs 00000000
Jun 13 13:19:10 d1 pluto[2771]: | v1 state object #1 found, in STATE_MAIN_R1
Jun 13 13:19:10 d1 pluto[2771]: | processing connection client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0[1] 10.0.12.2
Jun 13 13:19:10 d1 pluto[2771]: | checking NAT-t: enabled and RFC 3947 (NAT-Traversal)
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: NAT-Traversal: Result using RFC 3947 (NAT-Traversal) sender port 500: no NAT detected
Jun 13 13:19:10 d1 pluto[2771]: | inserting event EVENT_NAT_T_KEEPALIVE, timeout in 20 seconds
Jun 13 13:19:10 d1 pluto[2771]: | event added after event EVENT_v1_RETRANSMIT for #1
Jun 13 13:19:10 d1 pluto[2771]: | crypto helper -1 doing build_kenonce; request ID 0
Jun 13 13:19:10 d1 pluto[2771]: | main inI2_outR2: calculated ke+nonce, sending R2
Jun 13 13:19:10 d1 pluto[2771]: | processing connection client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0[1] 10.0.12.2
Jun 13 13:19:10 d1 pluto[2771]: | no IKE message padding required
Jun 13 13:19:10 d1 pluto[2771]: | main inI2_outR2: starting async DH calculation (group=5)
Jun 13 13:19:10 d1 pluto[2771]: | started looking for secret for 10.0.11.2->10.0.12.2 of kind PPK_PSK
Jun 13 13:19:10 d1 pluto[2771]: | actually looking for secret for 10.0.11.2->10.0.12.2 of kind PPK_PSK
Jun 13 13:19:10 d1 pluto[2771]: | line 1: key type PPK_PSK(10.0.11.2) to type PPK_PSK 
Jun 13 13:19:10 d1 pluto[2771]: | 1: compared key (none) to 10.0.11.2 / 10.0.12.2 -> 2
Jun 13 13:19:10 d1 pluto[2771]: | 2: compared key (none) to 10.0.11.2 / 10.0.12.2 -> 2
Jun 13 13:19:10 d1 pluto[2771]: | line 1: match=2 
Jun 13 13:19:10 d1 pluto[2771]: | best_match 0>2 best=0xb7807430 (line=1)
Jun 13 13:19:10 d1 pluto[2771]: | line 2: key type PPK_PSK(10.0.11.2) to type PPK_RSA 
Jun 13 13:19:10 d1 pluto[2771]: | concluding with best_match=2 best=0xb7807430 (lineno=1)
Jun 13 13:19:10 d1 pluto[2771]: | parent1 type: 2 group: 5 len: 2672 
Jun 13 13:19:10 d1 pluto[2771]: | crypto helper -1 doing compute dh+iv (V1 Phase 1); request ID 0
Jun 13 13:19:10 d1 pluto[2771]: | main inI2_outR2: calculated DH finished
Jun 13 13:19:10 d1 pluto[2771]: | processing connection client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0[1] 10.0.12.2
Jun 13 13:19:10 d1 pluto[2771]: | started dh_secretiv, returned: stf=STF_INLINE 
Jun 13 13:19:10 d1 pluto[2771]: | complete state transition with STF_OK
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: transition from state STATE_MAIN_R1 to state STATE_MAIN_R2
Jun 13 13:19:10 d1 pluto[2771]: | deleting event for #1
Jun 13 13:19:10 d1 pluto[2771]: | sending reply packet to 10.0.12.2:500 (from port 500)
Jun 13 13:19:10 d1 pluto[2771]: | sending 284 bytes for STATE_MAIN_R1 through eth1:500 to 10.0.12.2:500 (using #1)
Jun 13 13:19:10 d1 pluto[2771]: | inserting event EVENT_v1_RETRANSMIT, timeout in 10 seconds for #1
Jun 13 13:19:10 d1 pluto[2771]: | event added after event EVENT_PENDING_DDNS
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: STATE_MAIN_R2: sent MR2, expecting MI3
Jun 13 13:19:10 d1 pluto[2771]: | modecfg pull: noquirk policy:pull not-client
Jun 13 13:19:10 d1 pluto[2771]: | phase 1 is done, looking for phase 2 to unpend
Jun 13 13:19:10 d1 pluto[2771]: | complete state transition with STF_INLINE
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: ASSERTION FAILED at /usr/src/redhat/BUILD/libreswan-3.9/programs/pluto/ikev1.c:2290: md == NULL
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: using kernel interface: klips
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: interface ipsec0/eth1 10.0.11.2 at 4500
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: interface ipsec0/eth1 10.0.11.2 at 500
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: | SElinux: disabled, could not open /sys/fs/selinux/enforce or /selinux/enforce
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: fips mode=disabled;
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: SElinux=disabled
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: config setup options:
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: configdir=/etc, configfile=/etc/ipsec.conf, secrets=/etc/ipsec.secrets, ipsecdir=/etc/ipsec.d, dumpdir=/var/run/pluto, statsbin=unset
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: sbindir=/usr/sbin, libexecdir=/usr/libexec/ipsec
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: pluto_version=3.master-201424.git, pluto_vendorid=OE-Libreswan-3.master-201424.git
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: nhelpers=0, uniqueids=yes, retransmits=yes, force-busy=no
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: ikeport=500, strictcrlpolicy=no, crlcheckinterval=0, listen=<any>
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: secctx-attr-value=<unsupported>
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: myid = (none)
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: debug control+controlmore
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: nat-traversal=yes, keep-alive=20, nat-ikeport=4500
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: virtual-private (%priv):
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: ESP algorithms supported:
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm ESP encrypt: id=3, name=ESP_3DES, ivlen=64, keysizemin=192, keysizemax=192
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm ESP encrypt: id=6, name=ESP_CAST, ivlen=64, keysizemin=128, keysizemax=128
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm ESP encrypt: id=12, name=ESP_AES, ivlen=128, keysizemin=128, keysizemax=256
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm ESP encrypt: id=252, name=ESP_SERPENT, ivlen=128, keysizemin=128, keysizemax=256
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm ESP encrypt: id=253, name=ESP_TWOFISH, ivlen=128, keysizemin=128, keysizemax=256
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm ESP auth attr: id=1, name=AUTH_ALGORITHM_HMAC_MD5, keysizemin=128, keysizemax=128
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm ESP auth attr: id=2, name=AUTH_ALGORITHM_HMAC_SHA1, keysizemin=160, keysizemax=160
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm ESP auth attr: id=9, name=AUTH_ALGORITHM_AES_CBC, keysizemin=128, keysizemax=128
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: IKE algorithms supported:
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE encrypt: v1id=5, v1name=OAKLEY_3DES_CBC, v2id=3, v2name=3DES, blocksize=8, keydeflen=192
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE encrypt: v1id=7, v1name=OAKLEY_AES_CBC, v2id=12, v2name=AES_CBC, blocksize=16, keydeflen=128
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE encrypt: v1id=65004, v1name=OAKLEY_SERPENT_CBC, v2id=65004, v2name=SERPENT_CBC, blocksize=16, keydeflen=128
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE encrypt: v1id=65005, v1name=OAKLEY_TWOFISH_CBC, v2id=65005, v2name=TWOFISH_CBC, blocksize=16, keydeflen=128
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE encrypt: v1id=65289, v1name=OAKLEY_TWOFISH_CBC_SSH, v2id=65289, v2name=TWOFISH_CBC_SSH, blocksize=16, keydeflen=128
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE hash: id=1, name=OAKLEY_MD5, hashsize=16
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE hash: id=2, name=OAKLEY_SHA1, hashsize=20
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE hash: id=4, name=OAKLEY_SHA2_256, hashsize=32
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE hash: id=5, name=OAKLEY_SHA2_384, hashsize=48
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE hash: id=6, name=OAKLEY_SHA2_512, hashsize=64
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE dh group: id=2, name=OAKLEY_GROUP_MODP1024, bits=1024
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE dh group: id=5, name=OAKLEY_GROUP_MODP1536, bits=1536
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE dh group: id=14, name=OAKLEY_GROUP_MODP2048, bits=2048
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE dh group: id=15, name=OAKLEY_GROUP_MODP3072, bits=3072
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE dh group: id=16, name=OAKLEY_GROUP_MODP4096, bits=4096
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE dh group: id=17, name=OAKLEY_GROUP_MODP6144, bits=6144
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE dh group: id=18, name=OAKLEY_GROUP_MODP8192, bits=8192
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE dh group: id=22, name=OAKLEY_GROUP_DH22, bits=1024
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE dh group: id=23, name=OAKLEY_GROUP_DH23, bits=2048
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: algorithm IKE dh group: id=24, name=OAKLEY_GROUP_DH24, bits=2048
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: stats db_ops: {curr_cnt, total_cnt, maxsz} :context={0,0,0} trans={0,0,0} attrs={0,0,0} 
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: Connection list:
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0": 192.168.11.0/24===10.0.11.2[MS+XS+S=C]---10.0.11.1...%any[+MC+XC+S=C]===192.168.11.100/32; unrouted; eroute owner: #0
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0":     oriented; my_ip=192.168.11.1; their_ip=unset;
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0":   xauth info: us:server, them:client, method:file; my_xauthuser=[any]; their_xauthuser=[any]; ;
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0":   modecfg info: us:server, them:client, modecfg policy:pull, dns1:unset, dns2:unset, domain:unset, banner:unset;
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0":   labeled_ipsec:no, loopback:no; 
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0":    policy_label:unset; 
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0":   ike_life: 21600s; ipsec_life: 32400s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 3;
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0":   sha2_truncbug:no; initial_contact:no; cisco_unity:no; send_vendorid:no;
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0":   policy: PSK+ENCRYPT+TUNNEL+PFS+DONT_REKEY+XAUTH+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW; 
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0":   conn_prio: 24,32; interface: eth1; metric: 0; mtu: unset; sa_prio:auto;
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0":   newest ISAKMP SA: #0; newest IPsec SA: #0; 
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1]: 192.168.11.0/24===10.0.11.2[MS+XS+S=C]---10.0.11.1...10.0.12.2[+MC+XC+S=C]===192.168.11.100/32; unrouted; eroute owner: #0
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1]:     oriented; my_ip=192.168.11.1; their_ip=unset;
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1]:   xauth info: us:server, them:client, method:file; my_xauthuser=[any]; their_xauthuser=[any]; ;
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1]:   modecfg info: us:server, them:client, modecfg policy:pull, dns1:unset, dns2:unset, domain:unset, banner:unset;
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1]:   labeled_ipsec:no, loopback:no; 
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1]:    policy_label:unset; 
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1]:   ike_life: 21600s; ipsec_life: 32400s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 3;
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1]:   sha2_truncbug:no; initial_contact:no; cisco_unity:no; send_vendorid:no;
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1]:   policy: PSK+ENCRYPT+TUNNEL+PFS+DONT_REKEY+XAUTH+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW; 
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1]:   conn_prio: 24,32; interface: eth1; metric: 0; mtu: unset; sa_prio:auto;
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1]:   newest ISAKMP SA: #0; newest IPsec SA: #0; 
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: Total IPsec connections: loaded 2, active 0
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: State list:
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: #1: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2:500 STATE_MAIN_R2 (sent MR2, expecting MI3); EVENT_v1_RETRANSMIT in 10s; lastdpd=-1s(seq in:0 out:0); idle; import:not set
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: Shunt list:
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1:  
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: ABORT at /usr/src/redhat/BUILD/libreswan-3.9/programs/pluto/ikev1.c:2290
Jun 13 13:19:10 d1 pluto[2771]: "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"[1] 10.0.12.2 #1: ABORT at /usr/src/redhat/BUILD/libreswan-3.9/programs/pluto/ikev1.c:2290
Jun 13 13:19:10 d1 ipsec__plutorun: !pluto failure!:  exited with error status 134 (signal 6)
Jun 13 13:19:10 d1 ipsec__plutorun: restarting IPsec after pause...
Jun 13 13:19:20 d1 ipsec:  succeeded
Jun 13 13:19:20 d1 ipsec__plutorun: Starting Pluto subsystem...
Jun 13 13:19:20 d1 pluto[3982]: Using sql format key4.db, cert9.db
Jun 13 13:19:20 d1 pluto[3982]: Initializing NSS: DB is sql:/etc/ipsec.d
Jun 13 13:19:20 d1 pluto[3982]: NSS initialized
Jun 13 13:19:20 d1 pluto[3982]: libcap-ng support [disabled]
Jun 13 13:19:20 d1 pluto[3982]: FIPS HMAC integrity support [disabled]
Jun 13 13:19:20 d1 pluto[3982]: Linux audit support [disabled]
Jun 13 13:19:20 d1 pluto[3982]: Starting Pluto (Libreswan Version 3.master-201424.git XFRM(netkey) KLIPS NSS XAUTH_PAM KLIPS_MAST) pid:3982
Jun 13 13:19:20 d1 pluto[3982]: core dump dir: /var/run/pluto
Jun 13 13:19:20 d1 pluto[3982]: secrets file: /etc/ipsec.secrets
Jun 13 13:19:20 d1 pluto[3982]: leak-detective disabled
Jun 13 13:19:20 d1 pluto[3982]: SAref support [enabled]
Jun 13 13:19:20 d1 pluto[3982]: SAbind support [enabled]
Jun 13 13:19:20 d1 pluto[3982]: NSS crypto [enabled]
Jun 13 13:19:20 d1 pluto[3982]: XAUTH PAM support [enabled]
Jun 13 13:19:20 d1 pluto[3982]:    NAT-Traversal support  [enabled]
Jun 13 13:19:20 d1 pluto[3982]: | inserting event EVENT_REINIT_SECRET, timeout in 3600 seconds
Jun 13 13:19:20 d1 pluto[3982]: | event added at head of queue
Jun 13 13:19:20 d1 pluto[3982]: | inserting event EVENT_PENDING_DDNS, timeout in 60 seconds
Jun 13 13:19:20 d1 pluto[3982]: | event added at head of queue
Jun 13 13:19:20 d1 pluto[3982]: | inserting event EVENT_PENDING_PHASE2, timeout in 120 seconds
Jun 13 13:19:20 d1 pluto[3982]: | event added after event EVENT_PENDING_DDNS
Jun 13 13:19:20 d1 pluto[3982]: ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC_SSH: Ok (ret=0)
Jun 13 13:19:20 d1 pluto[3982]: ike_alg_register_enc(): Activating OAKLEY_TWOFISH_CBC: Ok (ret=0)
Jun 13 13:19:20 d1 pluto[3982]: ike_alg_register_enc(): Activating OAKLEY_SERPENT_CBC: Ok (ret=0)
Jun 13 13:19:20 d1 pluto[3982]: ike_alg_register_enc(): Activating OAKLEY_AES_CBC: Ok (ret=0)
Jun 13 13:19:20 d1 pluto[3982]: ike_alg_register_hash(): Activating OAKLEY_SHA2_512: Ok (ret=0)
Jun 13 13:19:20 d1 pluto[3982]: ike_alg_register_hash(): Activating OAKLEY_SHA2_384: Ok (ret=0)
Jun 13 13:19:20 d1 pluto[3982]: ike_alg_register_hash(): Activating OAKLEY_SHA2_256: Ok (ret=0)
Jun 13 13:19:20 d1 pluto[3982]: no crypto helpers will be started; all cryptographic operations will be done inline
Jun 13 13:19:20 d1 pluto[3982]: Using KLIPS IPsec interface code on 2.6.32.62
Jun 13 13:19:20 d1 pluto[3982]: | inserting event EVENT_SHUNT_SCAN, timeout in 120 seconds
Jun 13 13:19:20 d1 pluto[3982]: | event added after event EVENT_PENDING_DDNS
Jun 13 13:19:20 d1 pluto[3982]: | Changed path to directory '/etc/ipsec.d/cacerts'
Jun 13 13:19:20 d1 pluto[3982]:   loading CA cert file 'server.crt' (1701 bytes)
Jun 13 13:19:20 d1 pluto[3982]: |   TRUE
Jun 13 13:19:20 d1 pluto[3982]:   loading CA cert file 'ca.crt' (2366 bytes)
Jun 13 13:19:20 d1 pluto[3982]: |   TRUE
Jun 13 13:19:20 d1 pluto[3982]: | Changing to directory '/etc/ipsec.d/crls'
Jun 13 13:19:20 d1 pluto[3982]:   discarded crl file 'server.crl', bad size 0 bytes
Jun 13 13:19:20 d1 pluto[3982]: | inserting event EVENT_LOG_DAILY, timeout in 38440 seconds
Jun 13 13:19:20 d1 pluto[3982]: | event added after event EVENT_REINIT_SECRET
Jun 13 13:19:20 d1 pluto[3982]: listening for IKE messages
Jun 13 13:19:20 d1 pluto[3982]: | Inspecting interface lo 
Jun 13 13:19:20 d1 pluto[3982]: | found lo with address 127.0.0.1
Jun 13 13:19:20 d1 pluto[3982]: | Inspecting interface eth1 
Jun 13 13:19:20 d1 pluto[3982]: | found eth1 with address 10.0.11.2
Jun 13 13:19:20 d1 pluto[3982]: | Inspecting interface eth0 
Jun 13 13:19:20 d1 pluto[3982]: | found eth0 with address 192.168.11.1
Jun 13 13:19:20 d1 pluto[3982]: | Inspecting interface eth2 
Jun 13 13:19:20 d1 pluto[3982]: | found eth2 with address 172.16.16.2
Jun 13 13:19:20 d1 pluto[3982]: | Inspecting interface eth3 
Jun 13 13:19:20 d1 pluto[3982]: | found eth3 with address 192.168.192.111
Jun 13 13:19:20 d1 pluto[3982]: | Inspecting interface ipsec0 
Jun 13 13:19:20 d1 pluto[3982]: | found ipsec0 with address 10.0.11.2
Jun 13 13:19:20 d1 pluto[3982]: | IP interface eth3 192.168.192.111 has no matching ipsec* interface -- ignored
Jun 13 13:19:20 d1 pluto[3982]: | IP interface eth2 172.16.16.2 has no matching ipsec* interface -- ignored
Jun 13 13:19:20 d1 pluto[3982]: | IP interface eth0 192.168.11.1 has no matching ipsec* interface -- ignored
Jun 13 13:19:20 d1 pluto[3982]: adding interface ipsec0/eth1 10.0.11.2:500
Jun 13 13:19:20 d1 pluto[3982]: adding interface ipsec0/eth1 10.0.11.2:4500
Jun 13 13:19:20 d1 pluto[3982]: | IP interface lo 127.0.0.1 has no matching ipsec* interface -- ignored
Jun 13 13:19:20 d1 pluto[3982]: | could not open /proc/net/if_inet6
Jun 13 13:19:20 d1 pluto[3982]: | certs and keys locked by 'free_preshared_secrets'
Jun 13 13:19:20 d1 pluto[3982]: | certs and keys unlocked by 'free_preshard_secrets'
Jun 13 13:19:20 d1 pluto[3982]: loading secrets from "/etc/ipsec.secrets"
Jun 13 13:19:20 d1 pluto[3982]:     could not open host cert with nick name '/etc/ipsec.d/server.crt' in NSS DB
Jun 13 13:19:20 d1 pluto[3982]: "/etc/ipsec.secrets" line 2: NSS certficate not found
Jun 13 13:19:20 d1 pluto[3982]: loaded private key for keyid: PPK_RSA:AwEAAaBJJ
Jun 13 13:19:20 d1 pluto[3982]: | certs and keys locked by 'process_secret'
Jun 13 13:19:20 d1 pluto[3982]: | certs and keys unlocked by 'process_secret'
Jun 13 13:19:20 d1 pluto[3982]: loading secrets from "/etc/ipsec.d/client-0-client.psk"
Jun 13 13:19:20 d1 pluto[3982]: | Processing PSK at line 1: passed
Jun 13 13:19:20 d1 pluto[3982]: | certs and keys locked by 'process_secret'
Jun 13 13:19:20 d1 pluto[3982]: | certs and keys unlocked by 'process_secret'
Jun 13 13:19:20 d1 pluto[3982]: | next event EVENT_PENDING_DDNS in 60 seconds
Jun 13 13:19:21 d1 pluto[3984]: | calling addconn helper using execve
Jun 13 13:19:21 d1 pluto[3982]: |  
Jun 13 13:19:21 d1 pluto[3982]: | *received whack message
Jun 13 13:19:21 d1 pluto[3982]: | find_host_pair_conn (check_connection_end): 10.0.11.2:500 %any:500 -> hp:none 
Jun 13 13:19:21 d1 pluto[3982]: | Added new connection client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0 with policy PSK+ENCRYPT+TUNNEL+PFS+DONT_REKEY+XAUTH+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW
Jun 13 13:19:21 d1 pluto[3982]: | counting wild cards for (none) is 15
Jun 13 13:19:21 d1 pluto[3982]: | counting wild cards for (none) is 15
Jun 13 13:19:21 d1 pluto[3982]: | based upon policy, the connection is a template.
Jun 13 13:19:21 d1 pluto[3982]: | connect_to_host_pair: 10.0.11.2:500 0.0.0.0:500 -> hp:none 
Jun 13 13:19:21 d1 pluto[3982]: added connection description "client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0"
Jun 13 13:19:21 d1 pluto[3982]: | 192.168.11.0/24===10.0.11.2[MS+XS+S=C]---10.0.11.1...%any[+MC+XC+S=C]===192.168.11.100/32
Jun 13 13:19:21 d1 pluto[3982]: | ike_life: 21600s; ipsec_life: 32400s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 3; policy: PSK+ENCRYPT+TUNNEL+PFS+DONT_REKEY+XAUTH+MODECFG_PULL+IKEV2_ALLOW+SAREF_TRACK+IKE_FRAG_ALLOW
Jun 13 13:19:21 d1 pluto[3982]: | * processed 0 messages from cryptographic helpers 
Jun 13 13:19:21 d1 pluto[3982]: | next event EVENT_PENDING_DDNS in 59 seconds
Jun 13 13:19:21 d1 pluto[3982]: | next event EVENT_PENDING_DDNS in 59 seconds
Jun 13 13:19:21 d1 pluto[3982]: | next event EVENT_PENDING_DDNS in 59 seconds
Jun 13 13:19:21 d1 pluto[3982]: | reaped addconn helper child
-------------- next part --------------
# automatically generated file - DO NOT EDIT
#
conn client_0-client_sn-sn_192.168.11.0_24-0.0.0.0_0
	also=client_0-client
	leftsourceip=192.168.11.1
	leftsubnet=192.168.11.0/24
	right=%any
	auto=add
conn client_0-client
	left=%defaultroute
	authby=secret
	auth=esp
	pfs=yes
	disablearrivalcheck=no
	rekey=no
	xauthby=file
	leftxauthserver=yes
	rightxauthclient=yes
	leftmodecfgserver=yes
	rightmodecfgclient=yes
	modecfgpull=yes
	rightsubnet=192.168.11.100/32
	keylife=540m
	ikelifetime=360m
	keyingtries=3


More information about the Swan-dev mailing list