[Swan] repetitive reestablishment of ipsec

Oguz Yilmaz oguzyilmazlist at gmail.com
Fri Jan 4 00:14:48 EET 2013


This issue was related to local scripts. No such repetitive restart
occurs normally. Sorry for late realise.


--
Oguz YILMAZ


On Wed, Jan 2, 2013 at 11:40 PM, Philippe Vouters
<philippe.vouters at laposte.net> wrote:
> Dear Oguz,
>
> Any news since Paul's and my last mail. My last mail was containing a
> connection configuration example to an actual Cisco router.
>
> Kind regards,
>
> Philippe Vouters (Fontainebleau/France)
> URL: http://vouters.dyndns.org/
> SIP: sip:Vouters at sip.linphone.org
>
> Le 02/01/2013 13:43, Oguz Yilmaz a écrit :
>>
>> Debug with only control is below. I have suspected DPD and close it.
>> However, I see this issue is not about DPD.
>>
>> My problems were:
>>
>> 1- Why it takes about 2 minutes after restart of ipsec to establish
>> connection?
>> 2- Why it reestablish connection after about 3 minutes repetitively?
>>
>>
>>
>> Jan  2 14:34:19 2013 ipsec__plutorun: Starting Pluto subsystem...
>> Jan  2 14:34:19 2013 pluto[8551]: nss directory plutomain: /etc/ipsec.d
>> Jan  2 14:34:19 2013 pluto[8551]: NSS Initialized
>> Jan  2 14:34:19 2013 pluto[8551]: FIPS integrity support [disabled]
>> Jan  2 14:34:19 2013 pluto[8551]: libcap-ng support [enabled]
>> Jan  2 14:34:19 2013 pluto[8551]: Linux audit support [disabled]
>> Jan  2 14:34:19 2013 pluto[8551]: Starting Pluto (Libreswan Version
>> 3.0; Vendor ID OENiHcUfspQs) pid:8551
>> Jan  2 14:34:19 2013 pluto[8551]: Not able to open
>> /proc/sys/crypto/fips_enabled, returning non-fips mode
>> Jan  2 14:34:19 2013 pluto[8551]: Pluto is NOT running in FIPS mode
>> Jan  2 14:34:19 2013 pluto[8551]: core dump dir: /var/run/pluto
>> Jan  2 14:34:19 2013 pluto[8551]: secrets file: /etc/ipsec.secrets
>> Jan  2 14:34:19 2013 pluto[8551]: LEAK_DETECTIVE support [disabled]
>> Jan  2 14:34:19 2013 pluto[8551]: OCF support for IKE [disabled]
>> Jan  2 14:34:19 2013 pluto[8551]: SAref support [disabled]: Protocol
>> not available
>> Jan  2 14:34:19 2013 pluto[8551]: SAbind support [disabled]: Protocol
>> not available
>> Jan  2 14:34:19 2013 pluto[8551]: NSS crypto [enabled]
>> Jan  2 14:34:19 2013 pluto[8551]: XAUTH PAM support [enabled]
>> Jan  2 14:34:19 2013 pluto[8551]: HAVE_STATSD notification support
>> [disabled]
>> Jan  2 14:34:19 2013 pluto[8551]: Setting NAT-Traversal port-4500
>> floating to off
>> Jan  2 14:34:19 2013 pluto[8551]:    port floating activation criteria
>> nat_t=0/port_float=1
>> Jan  2 14:34:19 2013 pluto[8551]:    NAT-Traversal support  [disabled]
>> Jan  2 14:34:19 2013 pluto[8551]: | inserting event
>> EVENT_REINIT_SECRET, timeout in 3600 seconds
>> Jan  2 14:34:19 2013 pluto[8551]: | inserting event
>> EVENT_PENDING_DDNS, timeout in 60 seconds
>> Jan  2 14:34:19 2013 pluto[8551]: | inserting event
>> EVENT_PENDING_PHASE2, timeout in 120 seconds
>> Jan  2 14:34:19 2013 pluto[8551]: ike_alg_register_enc(): Activating
>> OAKLEY_AES_CBC: Ok (ret=0)
>> Jan  2 14:34:19 2013 pluto[8551]: ike_alg_register_hash(): Activating
>> OAKLEY_SHA2_512: Ok (ret=0)
>> Jan  2 14:34:19 2013 pluto[8551]: ike_alg_register_hash(): Activating
>> OAKLEY_SHA2_384: Ok (ret=0)
>> Jan  2 14:34:19 2013 pluto[8551]: ike_alg_register_hash(): Activating
>> OAKLEY_SHA2_256: Ok (ret=0)
>> Jan  2 14:34:19 2013 pluto[8551]: no helpers will be started, all
>> cryptographic operations will be done inline
>> Jan  2 14:34:19 2013 pluto[8551]: Using Linux XFRM/NETKEY IPsec
>> interface code on 3.5.3
>> Jan  2 14:34:19 2013 pluto[8551]: ike_alg_register_enc(): Activating
>> aes_ccm_8: Ok (ret=0)
>> Jan  2 14:34:19 2013 pluto[8551]: ike_alg_add(): ERROR: algo_type
>> \'0\', algo_id \'0\', Algorithm type already exists
>> Jan  2 14:34:19 2013 pluto[8551]: ike_alg_register_enc(): Activating
>> aes_ccm_12: FAILED (ret=-17)
>> Jan  2 14:34:19 2013 pluto[8551]: ike_alg_add(): ERROR: algo_type
>> \'0\', algo_id \'0\', Algorithm type already exists
>> Jan  2 14:34:19 2013 pluto[8551]: ike_alg_register_enc(): Activating
>> aes_ccm_16: FAILED (ret=-17)
>> Jan  2 14:34:19 2013 pluto[8551]: ike_alg_add(): ERROR: algo_type
>> \'0\', algo_id \'0\', Algorithm type already exists
>> Jan  2 14:34:19 2013 pluto[8551]: ike_alg_register_enc(): Activating
>> aes_gcm_8: FAILED (ret=-17)
>> Jan  2 14:34:19 2013 pluto[8551]: ike_alg_add(): ERROR: algo_type
>> \'0\', algo_id \'0\', Algorithm type already exists
>> Jan  2 14:34:19 2013 pluto[8551]: ike_alg_register_enc(): Activating
>> aes_gcm_12: FAILED (ret=-17)
>> Jan  2 14:34:19 2013 pluto[8551]: ike_alg_add(): ERROR: algo_type
>> \'0\', algo_id \'0\', Algorithm type already exists
>> Jan  2 14:34:19 2013 pluto[8551]: ike_alg_register_enc(): Activating
>> aes_gcm_16: FAILED (ret=-17)
>> Jan  2 14:34:19 2013 pluto[8551]: | Changed path to directory
>> \'/etc/ipsec.d/cacerts\'
>> Jan  2 14:34:19 2013 pluto[8551]:   loaded CA cert file \'cacert.pem\'
>> (1143 bytes)
>> Jan  2 14:34:19 2013 pluto[8551]: Could not change to directory
>> \'/etc/ipsec.d/aacerts\': No such file or directory
>> Jan  2 14:34:19 2013 pluto[8551]: Could not change to directory
>> \'/etc/ipsec.d/crls\': 2 No such file or directory
>> Jan  2 14:34:19 2013 pluto[8551]: | inserting event EVENT_LOG_DAILY,
>> timeout in 33941 seconds
>> Jan  2 14:34:19 2013 pluto[8551]: listening for IKE messages
>> Jan  2 14:34:19 2013 pluto[8551]: adding interface eth9.102/eth9.102
>> LEFT_EXT_IP:500
>> Jan  2 14:34:19 2013 pluto[8551]: adding interface eth1/eth1 10.46.1.5:500
>> Jan  2 14:34:19 2013 pluto[8551]: adding interface eth0/eth0
>> 169.254.1.1:500
>> Jan  2 14:34:19 2013 pluto[8551]: adding interface lo/lo 127.0.0.1:500
>> Jan  2 14:34:19 2013 pluto[8551]: | found lo with address
>> 0000:0000:0000:0000:0000:0000:0000:0001
>> Jan  2 14:34:19 2013 pluto[8551]: adding interface lo/lo ::1:500
>> Jan  2 14:34:19 2013 pluto[8551]: loading secrets from
>> \"/etc/ipsec.secrets\"
>> Jan  2 14:34:19 2013 pluto[8551]: | id type added to
>> secret(0xb7b0acc0) PPK_PSK: LEFT_EXT_IP
>> Jan  2 14:34:19 2013 pluto[8551]: | id type added to
>> secret(0xb7b0acc0) PPK_PSK: RIGHT_EXT_IP
>> Jan  2 14:34:19 2013 pluto[8551]: | Processing PSK at line 2: passed
>> Jan  2 14:34:19 2013 pluto[8551]: | id type added to
>> secret(0xb7b0adc0) PPK_PSK: LEFT_EXT_IP
>> Jan  2 14:34:19 2013 pluto[8551]: | id type added to
>> secret(0xb7b0adc0) PPK_PSK: 10.6.202.3
>> Jan  2 14:34:19 2013 pluto[8551]: | Processing PSK at line 4: passed
>> Jan  2 14:34:19 2013 pluto[8551]: no secrets filename matched
>> \"/etc/ipsec.*.secrets\"
>> Jan  2 14:34:19 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 60
>> seconds
>> Jan  2 14:34:20 2013 pluto[8551]: |
>> Jan  2 14:34:20 2013 pluto[8551]: | *received whack message
>> Jan  2 14:34:20 2013 pluto[8551]: | Added new connection passthru with
>> policy PFS+IKEv2ALLOW+SAREFTRACK+PASS+NEVER_NEGOTIATE
>> Jan  2 14:34:20 2013 pluto[8551]: | counting wild cards for 10.46.1.5 is 0
>> Jan  2 14:34:20 2013 pluto[8551]: | counting wild cards for (none) is 15
>> Jan  2 14:34:20 2013 pluto[8551]: added connection description
>> \"passthru\"
>> Jan  2 14:34:20 2013 pluto[8551]: |
>> 10.46.0.0/16===10.46.1.5<10.46.1.5>...%any===10.46.0.0/16
>> Jan  2 14:34:20 2013 pluto[8551]: | ike_life: 3600s; ipsec_life:
>> 28800s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0; policy:
>> PFS+IKEv2ALLOW+SAREFTRACK+PASS+NEVER_NEGOTIATE
>> Jan  2 14:34:20 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:34:20 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 59
>> seconds
>> Jan  2 14:34:20 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 59
>> seconds
>> Jan  2 14:34:20 2013 pluto[8551]: |
>> Jan  2 14:34:20 2013 pluto[8551]: | *received whack message
>> Jan  2 14:34:20 2013 pluto[8551]: | Added new connection merkezvpn/0x1
>> with policy PSK+ENCRYPT+TUNNEL+PFS+IKEv2ALLOW+SAREFTRACK
>> Jan  2 14:34:20 2013 pluto[8551]: | from whack: got --esp=3des-md5-96
>> Jan  2 14:34:20 2013 pluto[8551]: | esp string values:
>> 3DES(3)_000-MD5(1)_096
>> Jan  2 14:34:20 2013 pluto[8551]: | ike (phase1) algorihtm values:
>> 3DES_CBC(5)_000-MD5(1)_000-MODP1024(2)
>> Jan  2 14:34:20 2013 pluto[8551]: | counting wild cards for LEFT_EXT_IP is
>> 0
>> Jan  2 14:34:20 2013 pluto[8551]: | counting wild cards for 10.6.202.3 is
>> 0
>> Jan  2 14:34:20 2013 pluto[8551]: | alg_info_addref() alg_info->ref_cnt=1
>> Jan  2 14:34:20 2013 pluto[8551]: | alg_info_addref() alg_info->ref_cnt=1
>> Jan  2 14:34:20 2013 pluto[8551]: added connection description
>> \"merkezvpn/0x1\"
>> Jan  2 14:34:20 2013 pluto[8551]: |
>>
>> 10.46.0.0/16===LEFT_EXT_IP<LEFT_EXT_IP>---10.46.1.5...RIGHT_EXT_IP<RIGHT_EXT_IP>[10.6.202.3]===10.6.0.0/16
>> Jan  2 14:34:20 2013 pluto[8551]: | ike_life: 86400s; ipsec_life:
>> 86400s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0; policy:
>> PSK+ENCRYPT+TUNNEL+PFS+IKEv2ALLOW+SAREFTRACK
>> Jan  2 14:34:20 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:34:20 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 59
>> seconds
>> Jan  2 14:34:20 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 59
>> seconds
>> Jan  2 14:34:20 2013 pluto[8551]: |
>> Jan  2 14:34:20 2013 pluto[8551]: | *received whack message
>> Jan  2 14:34:20 2013 pluto[8551]: | Added new connection merkezvpn/0x2
>> with policy PSK+ENCRYPT+TUNNEL+PFS+IKEv2ALLOW+SAREFTRACK
>> Jan  2 14:34:20 2013 pluto[8551]: | from whack: got --esp=3des-md5-96
>> Jan  2 14:34:20 2013 pluto[8551]: | esp string values:
>> 3DES(3)_000-MD5(1)_096
>> Jan  2 14:34:20 2013 pluto[8551]: | ike (phase1) algorihtm values:
>> 3DES_CBC(5)_000-MD5(1)_000-MODP1024(2)
>> Jan  2 14:34:20 2013 pluto[8551]: | counting wild cards for LEFT_EXT_IP is
>> 0
>> Jan  2 14:34:20 2013 pluto[8551]: | counting wild cards for 10.6.202.3 is
>> 0
>> Jan  2 14:34:20 2013 pluto[8551]: | alg_info_addref() alg_info->ref_cnt=1
>> Jan  2 14:34:20 2013 pluto[8551]: | alg_info_addref() alg_info->ref_cnt=1
>> Jan  2 14:34:20 2013 pluto[8551]: added connection description
>> \"merkezvpn/0x2\"
>> Jan  2 14:34:20 2013 pluto[8551]: |
>>
>> 10.46.0.0/16===LEFT_EXT_IP<LEFT_EXT_IP>---10.46.1.5...RIGHT_EXT_IP<RIGHT_EXT_IP>[10.6.202.3]===192.168.2.0/24
>> Jan  2 14:34:20 2013 pluto[8551]: | ike_life: 86400s; ipsec_life:
>> 86400s; rekey_margin: 540s; rekey_fuzz: 100%; keyingtries: 0; policy:
>> PSK+ENCRYPT+TUNNEL+PFS+IKEv2ALLOW+SAREFTRACK
>> Jan  2 14:34:20 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:34:20 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 59
>> seconds
>> Jan  2 14:34:20 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 59
>> seconds
>> Jan  2 14:34:20 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 59
>> seconds
>> Jan  2 14:35:05 2013 pluto[8551]: |
>> Jan  2 14:35:05 2013 pluto[8551]: | *received whack message
>> Jan  2 14:35:05 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:35:05 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 14
>> seconds
>> Jan  2 14:35:05 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 14
>> seconds
>> Jan  2 14:35:19 2013 pluto[8551]: |
>> Jan  2 14:35:19 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 0
>> seconds
>> Jan  2 14:35:19 2013 pluto[8551]: | *time to handle event
>> Jan  2 14:35:19 2013 pluto[8551]: | handling event EVENT_PENDING_DDNS
>> Jan  2 14:35:19 2013 pluto[8551]: | event after this is
>> EVENT_PENDING_PHASE2 in 60 seconds
>> Jan  2 14:35:19 2013 pluto[8551]: | inserting event
>> EVENT_PENDING_DDNS, timeout in 60 seconds
>> Jan  2 14:35:19 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 60
>> seconds
>> Jan  2 14:35:59 2013 pluto[8551]: |
>> Jan  2 14:35:59 2013 pluto[8551]: | *received whack message
>> Jan  2 14:35:59 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:35:59 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 20
>> seconds
>> Jan  2 14:35:59 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 20
>> seconds
>> Jan  2 14:36:05 2013 pluto[8551]: |
>> Jan  2 14:36:05 2013 pluto[8551]: | *received whack message
>> Jan  2 14:36:05 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:36:05 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 14
>> seconds
>> Jan  2 14:36:05 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 14
>> seconds
>> Jan  2 14:36:09 2013 pluto[8551]: |
>> Jan  2 14:36:09 2013 pluto[8551]: | *received whack message
>> Jan  2 14:36:09 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:36:09 2013 pluto[8551]: \"merkezvpn/0x1\": terminating SAs
>> using this connection
>> Jan  2 14:36:09 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:36:09 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 10
>> seconds
>> Jan  2 14:36:09 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 10
>> seconds
>> Jan  2 14:36:10 2013 pluto[8551]: |
>> Jan  2 14:36:10 2013 pluto[8551]: | *received whack message
>> Jan  2 14:36:10 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:36:10 2013 pluto[8551]: | kernel_alg_db_new() will return
>> p_new->protoid=3, p_new->trans_cnt=1
>> Jan  2 14:36:10 2013 pluto[8551]: | kernel_alg_db_new()     trans[0]:
>> transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=1
>> Jan  2 14:36:10 2013 pluto[8551]: | returning new proposal from esp_info
>> Jan  2 14:36:10 2013 pluto[8551]: | creating state object #1 at 0xb7b10fc8
>> Jan  2 14:36:10 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:36:10 2013 pluto[8551]: | ICOOKIE:  f0 8e 7a 00  1a 12 b6 82
>> Jan  2 14:36:10 2013 pluto[8551]: | RCOOKIE:  00 00 00 00  00 00 00 00
>> Jan  2 14:36:10 2013 pluto[8551]: | state hash entry 24
>> Jan  2 14:36:10 2013 pluto[8551]: | inserting state object #1
>> Jan  2 14:36:10 2013 pluto[8551]: | inserting event EVENT_SO_DISCARD,
>> timeout in 0 seconds for #1
>> Jan  2 14:36:10 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:36:10 2013 pluto[8551]: | Queuing pending Quick Mode with
>> RIGHT_EXT_IP \"merkezvpn/0x1\"
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #1: initiating Main
>> Mode
>> Jan  2 14:36:10 2013 pluto[8551]: | sending 120 bytes for main_outI1
>> through eth9.102:500 to RIGHT_EXT_IP:500 (using #1)
>> Jan  2 14:36:10 2013 pluto[8551]: | inserting event EVENT_RETRANSMIT,
>> timeout in 10 seconds for #1
>> Jan  2 14:36:10 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:36:10 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 9
>> seconds
>> Jan  2 14:36:10 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 9
>> seconds
>> Jan  2 14:36:10 2013 pluto[8551]: |
>> Jan  2 14:36:10 2013 pluto[8551]: | *received 84 bytes from
>> RIGHT_EXT_IP:500 on eth9.102 (port=500)
>> Jan  2 14:36:10 2013 pluto[8551]: |  processing version=1.0 packet
>> with exchange type=ISAKMP_XCHG_IDPROT (2)
>> Jan  2 14:36:10 2013 pluto[8551]: | ICOOKIE:  f0 8e 7a 00  1a 12 b6 82
>> Jan  2 14:36:10 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  01 cf f6 69
>> Jan  2 14:36:10 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:36:10 2013 pluto[8551]: | v1 state object not found
>> Jan  2 14:36:10 2013 pluto[8551]: | ICOOKIE:  f0 8e 7a 00  1a 12 b6 82
>> Jan  2 14:36:10 2013 pluto[8551]: | RCOOKIE:  00 00 00 00  00 00 00 00
>> Jan  2 14:36:10 2013 pluto[8551]: | state hash entry 24
>> Jan  2 14:36:10 2013 pluto[8551]: | v1 peer and cookies match on #1,
>> provided msgid 00000000 vs 00000000
>> Jan  2 14:36:10 2013 pluto[8551]: | v1 state object #1 found, in
>> STATE_MAIN_I1
>> Jan  2 14:36:10 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:36:10 2013 pluto[8551]: | started looking for secret for
>> LEFT_EXT_IP->10.6.202.3 of kind PPK_PSK
>> Jan  2 14:36:10 2013 pluto[8551]: | actually looking for secret for
>> LEFT_EXT_IP->10.6.202.3 of kind PPK_PSK
>> Jan  2 14:36:10 2013 pluto[8551]: | 1: compared key 10.6.202.3 to
>> LEFT_EXT_IP / 10.6.202.3 -> 4
>> Jan  2 14:36:10 2013 pluto[8551]: | 2: compared key LEFT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 12
>> Jan  2 14:36:10 2013 pluto[8551]: | line 2: match=12
>> Jan  2 14:36:10 2013 pluto[8551]: | best_match 0>12 best=0xb7b0adc0
>> (line=2)
>> Jan  2 14:36:10 2013 pluto[8551]: | 1: compared key RIGHT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 0
>> Jan  2 14:36:10 2013 pluto[8551]: | 2: compared key LEFT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 8
>> Jan  2 14:36:10 2013 pluto[8551]: | line 1: match=8
>> Jan  2 14:36:10 2013 pluto[8551]: | concluding with best_match=12
>> best=0xb7b0adc0 (lineno=2)
>> Jan  2 14:36:10 2013 pluto[8551]: | helper -1 doing build_kenonce op id: 0
>> Jan  2 14:36:10 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:36:10 2013 pluto[8551]: | ICOOKIE:  f0 8e 7a 00  1a 12 b6 82
>> Jan  2 14:36:10 2013 pluto[8551]: | RCOOKIE:  00 00 00 00  00 00 00 00
>> Jan  2 14:36:10 2013 pluto[8551]: | state hash entry 24
>> Jan  2 14:36:10 2013 pluto[8551]: | ICOOKIE:  f0 8e 7a 00  1a 12 b6 82
>> Jan  2 14:36:10 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  01 cf f6 69
>> Jan  2 14:36:10 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:36:10 2013 pluto[8551]: | inserting state object #1
>> Jan  2 14:36:10 2013 pluto[8551]: | complete state transition with STF_OK
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #1: transition
>> from state STATE_MAIN_I1 to state STATE_MAIN_I2
>> Jan  2 14:36:10 2013 pluto[8551]: | sending reply packet to
>> RIGHT_EXT_IP:500 (from port 500)
>> Jan  2 14:36:10 2013 pluto[8551]: | sending 180 bytes for
>> STATE_MAIN_I1 through eth9.102:500 to RIGHT_EXT_IP:500 (using #1)
>> Jan  2 14:36:10 2013 pluto[8551]: | inserting event EVENT_RETRANSMIT,
>> timeout in 10 seconds for #1
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #1: STATE_MAIN_I2:
>> sent MI2, expecting MR2
>> Jan  2 14:36:10 2013 pluto[8551]: | modecfg pull: noquirk policy:push
>> not-client
>> Jan  2 14:36:10 2013 pluto[8551]: | phase 1 is done, looking for phase
>> 2 to unpend
>> Jan  2 14:36:10 2013 pluto[8551]: | complete state transition with
>> STF_INLINE
>> Jan  2 14:36:10 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:36:10 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 9
>> seconds
>> Jan  2 14:36:10 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 9
>> seconds
>> Jan  2 14:36:10 2013 pluto[8551]: |
>> Jan  2 14:36:10 2013 pluto[8551]: | *received 256 bytes from
>> RIGHT_EXT_IP:500 on eth9.102 (port=500)
>> Jan  2 14:36:10 2013 pluto[8551]: |  processing version=1.0 packet
>> with exchange type=ISAKMP_XCHG_IDPROT (2)
>> Jan  2 14:36:10 2013 pluto[8551]: | ICOOKIE:  f0 8e 7a 00  1a 12 b6 82
>> Jan  2 14:36:10 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  01 cf f6 69
>> Jan  2 14:36:10 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:36:10 2013 pluto[8551]: | v1 peer and cookies match on #1,
>> provided msgid 00000000 vs 00000000
>> Jan  2 14:36:10 2013 pluto[8551]: | v1 state object #1 found, in
>> STATE_MAIN_I2
>> Jan  2 14:36:10 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #1: received
>> Vendor ID payload [Cisco-Unity]
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #1: received
>> Vendor ID payload [Dead Peer Detection]
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #1: ignoring
>> unknown Vendor ID payload [0945ede601cef66946d1645b37053c88]
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #1: received
>> Vendor ID payload [XAUTH]
>> Jan  2 14:36:10 2013 pluto[8551]: | started looking for secret for
>> LEFT_EXT_IP->10.6.202.3 of kind PPK_PSK
>> Jan  2 14:36:10 2013 pluto[8551]: | actually looking for secret for
>> LEFT_EXT_IP->10.6.202.3 of kind PPK_PSK
>> Jan  2 14:36:10 2013 pluto[8551]: | 1: compared key 10.6.202.3 to
>> LEFT_EXT_IP / 10.6.202.3 -> 4
>> Jan  2 14:36:10 2013 pluto[8551]: | 2: compared key LEFT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 12
>> Jan  2 14:36:10 2013 pluto[8551]: | line 2: match=12
>> Jan  2 14:36:10 2013 pluto[8551]: | best_match 0>12 best=0xb7b0adc0
>> (line=2)
>> Jan  2 14:36:10 2013 pluto[8551]: | 1: compared key RIGHT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 0
>> Jan  2 14:36:10 2013 pluto[8551]: | 2: compared key LEFT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 8
>> Jan  2 14:36:10 2013 pluto[8551]: | line 1: match=8
>> Jan  2 14:36:10 2013 pluto[8551]: | concluding with best_match=12
>> best=0xb7b0adc0 (lineno=2)
>> Jan  2 14:36:10 2013 pluto[8551]: | parent1 type: 7 group: 2 len: 2680
>> Jan  2 14:36:10 2013 pluto[8551]: | helper -1 doing compute dh+iv op id: 0
>> Jan  2 14:36:10 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:36:10 2013 pluto[8551]: | thinking about whether to send my
>> certificate:
>> Jan  2 14:36:10 2013 pluto[8551]: |   I have RSA key:
>> OAKLEY_PRESHARED_KEY cert.type: CERT_NONE
>> Jan  2 14:36:10 2013 pluto[8551]: |   sendcert: CERT_ALWAYSSEND and I
>> did not get a certificate request
>> Jan  2 14:36:10 2013 pluto[8551]: |   so do not send cert.
>> Jan  2 14:36:10 2013 pluto[8551]: | I did not send a certificate
>> because digital signatures are not being used. (PSK)
>> Jan  2 14:36:10 2013 pluto[8551]: |  I am not sending a certificate
>> request
>> Jan  2 14:36:10 2013 pluto[8551]: | complete state transition with STF_OK
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #1: transition
>> from state STATE_MAIN_I2 to state STATE_MAIN_I3
>> Jan  2 14:36:10 2013 pluto[8551]: | sending reply packet to
>> RIGHT_EXT_IP:500 (from port 500)
>> Jan  2 14:36:10 2013 pluto[8551]: | sending 60 bytes for STATE_MAIN_I2
>> through eth9.102:500 to RIGHT_EXT_IP:500 (using #1)
>> Jan  2 14:36:10 2013 pluto[8551]: | inserting event EVENT_RETRANSMIT,
>> timeout in 10 seconds for #1
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #1: STATE_MAIN_I3:
>> sent MI3, expecting MR3
>> Jan  2 14:36:10 2013 pluto[8551]: | modecfg pull: noquirk policy:push
>> not-client
>> Jan  2 14:36:10 2013 pluto[8551]: | phase 1 is done, looking for phase
>> 2 to unpend
>> Jan  2 14:36:10 2013 pluto[8551]: | complete state transition with
>> STF_INLINE
>> Jan  2 14:36:10 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:36:10 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 9
>> seconds
>> Jan  2 14:36:10 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 9
>> seconds
>> Jan  2 14:36:10 2013 pluto[8551]: |
>> Jan  2 14:36:10 2013 pluto[8551]: | *received 68 bytes from
>> RIGHT_EXT_IP:500 on eth9.102 (port=500)
>> Jan  2 14:36:10 2013 pluto[8551]: |  processing version=1.0 packet
>> with exchange type=ISAKMP_XCHG_IDPROT (2)
>> Jan  2 14:36:10 2013 pluto[8551]: | ICOOKIE:  f0 8e 7a 00  1a 12 b6 82
>> Jan  2 14:36:10 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  01 cf f6 69
>> Jan  2 14:36:10 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:36:10 2013 pluto[8551]: | v1 peer and cookies match on #1,
>> provided msgid 00000000 vs 00000000
>> Jan  2 14:36:10 2013 pluto[8551]: | v1 state object #1 found, in
>> STATE_MAIN_I3
>> Jan  2 14:36:10 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #1: Main mode peer
>> ID is ID_IPV4_ADDR: \'10.6.202.3\'
>> Jan  2 14:36:10 2013 pluto[8551]: | complete state transition with STF_OK
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #1: transition
>> from state STATE_MAIN_I3 to state STATE_MAIN_I4
>> Jan  2 14:36:10 2013 pluto[8551]: | inserting event EVENT_SA_REPLACE,
>> timeout in 85407 seconds for #1
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #1: STATE_MAIN_I4:
>> ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY
>> cipher=oakley_3des_cbc_192 prf=oakley_md5 group=modp1024}
>> Jan  2 14:36:10 2013 pluto[8551]: | modecfg pull: noquirk policy:push
>> not-client
>> Jan  2 14:36:10 2013 pluto[8551]: | phase 1 is done, looking for phase
>> 2 to unpend
>> Jan  2 14:36:10 2013 pluto[8551]: | unqueuing pending Quick Mode with
>> RIGHT_EXT_IP \"merkezvpn/0x1\" import:admin initiate
>> Jan  2 14:36:10 2013 pluto[8551]: | duplicating state object #1
>> Jan  2 14:36:10 2013 pluto[8551]: | creating state object #2 at 0xb7b25228
>> Jan  2 14:36:10 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:36:10 2013 pluto[8551]: | ICOOKIE:  f0 8e 7a 00  1a 12 b6 82
>> Jan  2 14:36:10 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  01 cf f6 69
>> Jan  2 14:36:10 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:36:10 2013 pluto[8551]: | inserting state object #2
>> Jan  2 14:36:10 2013 pluto[8551]: | inserting event EVENT_SO_DISCARD,
>> timeout in 0 seconds for #2
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #2: initiating
>> Quick Mode PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK {using
>> isakmp#1 msgid:726b70dc proposal=3DES(3)_192-MD5(1)_096
>> pfsgroup=OAKLEY_GROUP_MODP1024}
>> Jan  2 14:36:10 2013 pluto[8551]: | helper -1 doing build_kenonce op id: 0
>> Jan  2 14:36:10 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:36:10 2013 pluto[8551]: | kernel_alg_db_new() will return
>> p_new->protoid=3, p_new->trans_cnt=1
>> Jan  2 14:36:10 2013 pluto[8551]: | kernel_alg_db_new()     trans[0]:
>> transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=1
>> Jan  2 14:36:10 2013 pluto[8551]: | returning new proposal from esp_info
>> Jan  2 14:36:10 2013 pluto[8551]: | sending 292 bytes for quick_outI1
>> through eth9.102:500 to RIGHT_EXT_IP:500 (using #2)
>> Jan  2 14:36:10 2013 pluto[8551]: | inserting event EVENT_RETRANSMIT,
>> timeout in 10 seconds for #2
>> Jan  2 14:36:10 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:36:10 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 9
>> seconds
>> Jan  2 14:36:10 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 9
>> seconds
>> Jan  2 14:36:10 2013 pluto[8551]: |
>> Jan  2 14:36:10 2013 pluto[8551]: | *received 324 bytes from
>> RIGHT_EXT_IP:500 on eth9.102 (port=500)
>> Jan  2 14:36:10 2013 pluto[8551]: |  processing version=1.0 packet
>> with exchange type=ISAKMP_XCHG_QUICK (32)
>> Jan  2 14:36:10 2013 pluto[8551]: | ICOOKIE:  f0 8e 7a 00  1a 12 b6 82
>> Jan  2 14:36:10 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  01 cf f6 69
>> Jan  2 14:36:10 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:36:10 2013 pluto[8551]: | v1 peer and cookies match on #2,
>> provided msgid dc706b72 vs dc706b72
>> Jan  2 14:36:10 2013 pluto[8551]: | v1 state object #2 found, in
>> STATE_QUICK_I1
>> Jan  2 14:36:10 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #2: ignoring
>> informational payload, type IPSEC_RESPONDER_LIFETIME msgid=726b70dc
>> Jan  2 14:36:10 2013 pluto[8551]: | started looking for secret for
>> LEFT_EXT_IP->10.6.202.3 of kind PPK_PSK
>> Jan  2 14:36:10 2013 pluto[8551]: | actually looking for secret for
>> LEFT_EXT_IP->10.6.202.3 of kind PPK_PSK
>> Jan  2 14:36:10 2013 pluto[8551]: | 1: compared key 10.6.202.3 to
>> LEFT_EXT_IP / 10.6.202.3 -> 4
>> Jan  2 14:36:10 2013 pluto[8551]: | 2: compared key LEFT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 12
>> Jan  2 14:36:10 2013 pluto[8551]: | line 2: match=12
>> Jan  2 14:36:10 2013 pluto[8551]: | best_match 0>12 best=0xb7b0adc0
>> (line=2)
>> Jan  2 14:36:10 2013 pluto[8551]: | 1: compared key RIGHT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 0
>> Jan  2 14:36:10 2013 pluto[8551]: | 2: compared key LEFT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 8
>> Jan  2 14:36:10 2013 pluto[8551]: | line 1: match=8
>> Jan  2 14:36:10 2013 pluto[8551]: | concluding with best_match=12
>> best=0xb7b0adc0 (lineno=2)
>> Jan  2 14:36:10 2013 pluto[8551]: | helper -1 doing compute dh(p2) op id:
>> 0
>> Jan  2 14:36:10 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:36:10 2013 pluto[8551]: | our client is subnet 10.46.0.0/16
>> Jan  2 14:36:10 2013 pluto[8551]: | our client protocol/port is 0/0
>> Jan  2 14:36:10 2013 pluto[8551]: | peer client is subnet 10.6.0.0/16
>> Jan  2 14:36:10 2013 pluto[8551]: | peer client protocol/port is 0/0
>> Jan  2 14:36:10 2013 pluto[8551]: | install_ipsec_sa() for #2: inbound
>> and outbound
>> Jan  2 14:36:10 2013 pluto[8551]: | route owner of \"merkezvpn/0x1\"
>> unrouted: NULL; eroute owner: NULL
>> Jan  2 14:36:10 2013 pluto[8551]: | could_route called for
>> merkezvpn/0x1 (kind=CK_PERMANENT)
>> Jan  2 14:36:10 2013 pluto[8551]: | add inbound eroute 10.6.0.0/16:0
>> --0-> 10.46.0.0/16:0 => tun.10000 at LEFT_EXT_IP (raw_eroute)
>> Jan  2 14:36:10 2013 pluto[8551]: | raw_eroute result=1
>> Jan  2 14:36:10 2013 pluto[8551]: | sr for #2: unrouted
>> Jan  2 14:36:10 2013 pluto[8551]: | route owner of \"merkezvpn/0x1\"
>> unrouted: NULL; eroute owner: NULL
>> Jan  2 14:36:10 2013 pluto[8551]: | eroute_connection add eroute
>> 10.46.0.0/16:0 --0-> 10.6.0.0/16:0 => tun.0 at RIGHT_EXT_IP (raw_eroute)
>> Jan  2 14:36:10 2013 pluto[8551]: | raw_eroute result=1
>> Jan  2 14:36:10 2013 pluto[8551]: | command executing up-client
>> Jan  2 14:36:10 2013 pluto[8551]: | executing up-client: 2>&1
>> PLUTO_VERB=\'up-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0x1\' PLUTO_INTERFACE=\'eth9.102\'
>> PLUTO_NEXT_HOP=\'10.46.1.5\' PLUTO_ME=\'LEFT_EXT_IP\'
>> PLUTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'10.46.0.0\' PLUTO_MY_CLIENT_MASK=\'255.255.0.0\'
>> PLUTO_MY_PORT=\'0\' PLUTO_MY_PROTOCOL=\'0\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'10.6.0.0/16\' PLUTO_PEER_CLIENT_NET=\'10.6.0.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.0.0\' PLUTO_PEER_PORT=\'0\'
>> PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\' PLUTO_STACK=\'netkey\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK\'
>> PLUTO_CONN_ADDRFAMILY=\'ipv4\' PLUTO_XAUTH_USERNAME=\'\'
>> PLUTO_MY_SOURCEIP=\'10.46.1.5\' PLUTO_IS_PEER_CISCO=\'0\'
>> PLUTO_CISCO_DNS_INFO=\'\' PLUTO_CISCO_DOMAIN_INFO=\'\'
>> PLUTO_PEER_BANNER=\'\' PLUTO_NM_CONFIGURED=\'0\' ipsec _updown
>> Jan  2 14:36:10 2013 pluto[8551]: | popen(): cmd is 845 chars long
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd(   0):2>&1
>> PLUTO_VERB=\'up-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0x1\':
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd(  80):
>> PLUTO_INTERFACE=\'eth9.102\' PLUTO_NEXT_HOP=\'10.46.1.5\'
>> PLUTO_ME=\'LEFT_EXT_IP\' PL:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd(
>> 160):UTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'10.4:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 240):6.0.0\'
>> PLUTO_MY_CLIENT_MASK=\'255.255.0.0\' PLUTO_MY_PORT=\'0\'
>> PLUTO_MY_PROTOCOL=\'0:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 320):\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'10.6.0:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 400):.0/16\'
>> PLUTO_PEER_CLIENT_NET=\'10.6.0.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.0.0\' PLU:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 480):TO_PEER_PORT=\'0\'
>> PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\' PLUTO_STACK=\'netkey\'  :
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 560):
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK\'
>> PLUTO_CONN_:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 640):ADDRFAMILY=\'ipv4\'
>> PLUTO_XAUTH_USERNAME=\'\' PLUTO_MY_SOURCEIP=\'10.46.1.5\' PLUTO_IS:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 720):_PEER_CISCO=\'0\'
>> PLUTO_CISCO_DNS_INFO=\'\' PLUTO_CISCO_DOMAIN_INFO=\'\' PLUTO_PEER_BA:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 800):NNER=\'\'
>> PLUTO_NM_CONFIGURED=\'0\' ipsec _updown:
>> Jan  2 14:36:10 2013 pluto[8551]: | route_and_eroute: firewall_notified:
>> true
>> Jan  2 14:36:10 2013 pluto[8551]: | command executing prepare-client
>> Jan  2 14:36:10 2013 pluto[8551]: | executing prepare-client: 2>&1
>> PLUTO_VERB=\'prepare-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0x1\' PLUTO_INTERFACE=\'eth9.102\'
>> PLUTO_NEXT_HOP=\'10.46.1.5\' PLUTO_ME=\'LEFT_EXT_IP\'
>> PLUTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'10.46.0.0\' PLUTO_MY_CLIENT_MASK=\'255.255.0.0\'
>> PLUTO_MY_PORT=\'0\' PLUTO_MY_PROTOCOL=\'0\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'10.6.0.0/16\' PLUTO_PEER_CLIENT_NET=\'10.6.0.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.0.0\' PLUTO_PEER_PORT=\'0\'
>> PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\' PLUTO_STACK=\'netkey\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK\'
>> PLUTO_CONN_ADDRFAMILY=\'ipv4\' PLUTO_XAUTH_USERNAME=\'\'
>> PLUTO_MY_SOURCEIP=\'10.46.1.5\' PLUTO_IS_PEER_CISCO=\'0\'
>> PLUTO_CISCO_DNS_INFO=\'\' PLUTO_CISCO_DOMAIN_INFO=\'\'
>> PLUTO_PEER_BANNER=\'\' PLUTO_NM_CONFIGURED=\'0\' ipsec _updown
>> Jan  2 14:36:10 2013 pluto[8551]: | popen(): cmd is 850 chars long
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd(   0):2>&1
>> PLUTO_VERB=\'prepare-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd(  80):/0x1\'
>> PLUTO_INTERFACE=\'eth9.102\' PLUTO_NEXT_HOP=\'10.46.1.5\'
>> PLUTO_ME=\'LEFT_EXT_IP:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 160):8\'
>> PLUTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 240):\'10.46.0.0\'
>> PLUTO_MY_CLIENT_MASK=\'255.255.0.0\' PLUTO_MY_PORT=\'0\'
>> PLUTO_MY_PROTOC:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 320):OL=\'0\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'1:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 400):0.6.0.0/16\'
>> PLUTO_PEER_CLIENT_NET=\'10.6.0.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.0.0:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 480):\' PLUTO_PEER_PORT=\'0\'
>> PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\' PLUTO_STACK=\'netk:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 560):ey\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK\'
>> PLUTO_:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 640):CONN_ADDRFAMILY=\'ipv4\'
>> PLUTO_XAUTH_USERNAME=\'\' PLUTO_MY_SOURCEIP=\'10.46.1.5\' PLU:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 720):TO_IS_PEER_CISCO=\'0\'
>> PLUTO_CISCO_DNS_INFO=\'\' PLUTO_CISCO_DOMAIN_INFO=\'\' PLUTO_PE:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 800):ER_BANNER=\'\'
>> PLUTO_NM_CONFIGURED=\'0\' ipsec _updown:
>> Jan  2 14:36:10 2013 pluto[8551]: | command executing route-client
>> Jan  2 14:36:10 2013 pluto[8551]: | executing route-client: 2>&1
>> PLUTO_VERB=\'route-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0x1\' PLUTO_INTERFACE=\'eth9.102\'
>> PLUTO_NEXT_HOP=\'10.46.1.5\' PLUTO_ME=\'LEFT_EXT_IP\'
>> PLUTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'10.46.0.0\' PLUTO_MY_CLIENT_MASK=\'255.255.0.0\'
>> PLUTO_MY_PORT=\'0\' PLUTO_MY_PROTOCOL=\'0\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'10.6.0.0/16\' PLUTO_PEER_CLIENT_NET=\'10.6.0.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.0.0\' PLUTO_PEER_PORT=\'0\'
>> PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\' PLUTO_STACK=\'netkey\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK\'
>> PLUTO_CONN_ADDRFAMILY=\'ipv4\' PLUTO_XAUTH_USERNAME=\'\'
>> PLUTO_MY_SOURCEIP=\'10.46.1.5\' PLUTO_IS_PEER_CISCO=\'0\'
>> PLUTO_CISCO_DNS_INFO=\'\' PLUTO_CISCO_DOMAIN_INFO=\'\'
>> PLUTO_PEER_BANNER=\'\' PLUTO_NM_CONFIGURED=\'0\' ipsec _updown
>> Jan  2 14:36:10 2013 pluto[8551]: | popen(): cmd is 848 chars long
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd(   0):2>&1
>> PLUTO_VERB=\'route-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd(  80):x1\'
>> PLUTO_INTERFACE=\'eth9.102\' PLUTO_NEXT_HOP=\'10.46.1.5\'
>> PLUTO_ME=\'LEFT_EXT_IP\':
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 160):
>> PLUTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'1:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 240):0.46.0.0\'
>> PLUTO_MY_CLIENT_MASK=\'255.255.0.0\' PLUTO_MY_PORT=\'0\'
>> PLUTO_MY_PROTOCOL:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 320):=\'0\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'10.:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 400):6.0.0/16\'
>> PLUTO_PEER_CLIENT_NET=\'10.6.0.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.0.0\' :
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 480):PLUTO_PEER_PORT=\'0\'
>> PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\' PLUTO_STACK=\'netkey:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 560):\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK\'
>> PLUTO_CO:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 640):NN_ADDRFAMILY=\'ipv4\'
>> PLUTO_XAUTH_USERNAME=\'\' PLUTO_MY_SOURCEIP=\'10.46.1.5\' PLUTO:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 720):_IS_PEER_CISCO=\'0\'
>> PLUTO_CISCO_DNS_INFO=\'\' PLUTO_CISCO_DOMAIN_INFO=\'\' PLUTO_PEER:
>> Jan  2 14:36:10 2013 pluto[8551]: | cmd( 800):_BANNER=\'\'
>> PLUTO_NM_CONFIGURED=\'0\' ipsec _updown:
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #2: route-client
>> output: /usr/libexec/ipsec/_updown.netkey: doroute `ip route replace
>> 10.6.0.0/16 via 10.46.1.5 dev lo  src 10.46.1.5\' failed (RTNETLINK
>> answers: No such process)
>> Jan  2 14:36:10 2013 pluto[8551]: | route_and_eroute: instance
>> \"merkezvpn/0x1\", setting eroute_owner {spd=0xb7b0fa20,sr=0xb7b0fa20}
>> to #2 (was #0) (newest_ipsec_sa=#0)
>> Jan  2 14:36:10 2013 pluto[8551]: | complete state transition with STF_OK
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #2: transition
>> from state STATE_QUICK_I1 to state STATE_QUICK_I2
>> Jan  2 14:36:10 2013 pluto[8551]: | sending reply packet to
>> RIGHT_EXT_IP:500 (from port 500)
>> Jan  2 14:36:10 2013 pluto[8551]: | sending 52 bytes for
>> STATE_QUICK_I1 through eth9.102:500 to RIGHT_EXT_IP:500 (using #2)
>> Jan  2 14:36:10 2013 pluto[8551]: | inserting event EVENT_SA_REPLACE,
>> timeout in 85648 seconds for #2
>> Jan  2 14:36:10 2013 pluto[8551]: \"merkezvpn/0x1\" #2:
>> STATE_QUICK_I2: sent QI2, IPsec SA established tunnel mode
>> {ESP=>0xd0be1e86 <0xe6b68010 xfrm=3DES_0-HMAC_MD5 NATOA=none NATD=none
>> DPD=none}
>>
>>
>>
>>
>>
>> Jan  2 14:36:10 2013 pluto[8551]: | modecfg pull: noquirk policy:push
>> not-client
>> Jan  2 14:36:10 2013 pluto[8551]: | phase 1 is done, looking for phase
>> 2 to unpend
>> Jan  2 14:36:10 2013 pluto[8551]: | complete state transition with
>> STF_INLINE
>> Jan  2 14:36:10 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:36:10 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 9
>> seconds
>> Jan  2 14:36:10 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 9
>> seconds
>> Jan  2 14:36:19 2013 pluto[8551]: |
>> Jan  2 14:36:19 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 0
>> seconds
>> Jan  2 14:36:19 2013 pluto[8551]: | *time to handle event
>> Jan  2 14:36:19 2013 pluto[8551]: | handling event EVENT_PENDING_DDNS
>> Jan  2 14:36:19 2013 pluto[8551]: | event after this is
>> EVENT_PENDING_PHASE2 in 0 seconds
>> Jan  2 14:36:19 2013 pluto[8551]: | inserting event
>> EVENT_PENDING_DDNS, timeout in 60 seconds
>> Jan  2 14:36:19 2013 pluto[8551]: | handling event EVENT_PENDING_PHASE2
>> Jan  2 14:36:19 2013 pluto[8551]: | event after this is
>> EVENT_PENDING_DDNS in 60 seconds
>> Jan  2 14:36:19 2013 pluto[8551]: | inserting event
>> EVENT_PENDING_PHASE2, timeout in 120 seconds
>> Jan  2 14:36:19 2013 pluto[8551]: | pending review: connection
>> \"merkezvpn/0x1\" checked
>> Jan  2 14:36:19 2013 pluto[8551]: | pending review: connection
>> \"merkezvpn/0x2\" was not up, skipped
>> Jan  2 14:36:19 2013 pluto[8551]: | pending review: connection
>> \"passthru\" has no negotiated policy, skipped
>> Jan  2 14:36:19 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 60
>> seconds
>> Jan  2 14:36:28 2013 pluto[8551]: |
>> Jan  2 14:36:28 2013 pluto[8551]: | *received whack message
>> Jan  2 14:36:28 2013 pluto[8551]: | processing connection merkezvpn/0x2
>> Jan  2 14:36:28 2013 pluto[8551]: \"merkezvpn/0x2\": terminating SAs
>> using this connection
>> Jan  2 14:36:28 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:36:28 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 51
>> seconds
>> Jan  2 14:36:28 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 51
>> seconds
>> Jan  2 14:36:29 2013 pluto[8551]: |
>> Jan  2 14:36:29 2013 pluto[8551]: | *received whack message
>> Jan  2 14:36:29 2013 pluto[8551]: | processing connection merkezvpn/0x2
>> Jan  2 14:36:29 2013 pluto[8551]: | kernel_alg_db_new() will return
>> p_new->protoid=3, p_new->trans_cnt=1
>> Jan  2 14:36:29 2013 pluto[8551]: | kernel_alg_db_new()     trans[0]:
>> transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=1
>> Jan  2 14:36:29 2013 pluto[8551]: | returning new proposal from esp_info
>> Jan  2 14:36:29 2013 pluto[8551]: | duplicating state object #1
>> Jan  2 14:36:29 2013 pluto[8551]: | creating state object #3 at 0xb7b27cf8
>> Jan  2 14:36:29 2013 pluto[8551]: | processing connection merkezvpn/0x2
>> Jan  2 14:36:29 2013 pluto[8551]: | ICOOKIE:  f0 8e 7a 00  1a 12 b6 82
>> Jan  2 14:36:29 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  01 cf f6 69
>> Jan  2 14:36:29 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:36:29 2013 pluto[8551]: | inserting state object #3
>> Jan  2 14:36:29 2013 pluto[8551]: | inserting event EVENT_SO_DISCARD,
>> timeout in 0 seconds for #3
>> Jan  2 14:36:29 2013 pluto[8551]: \"merkezvpn/0x2\" #3: initiating
>> Quick Mode PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK {using
>> isakmp#1 msgid:8e20654a proposal=3DES(3)_192-MD5(1)_096
>> pfsgroup=OAKLEY_GROUP_MODP1024}
>> Jan  2 14:36:29 2013 pluto[8551]: | helper -1 doing build_kenonce op id: 0
>> Jan  2 14:36:29 2013 pluto[8551]: | processing connection merkezvpn/0x2
>> Jan  2 14:36:29 2013 pluto[8551]: | kernel_alg_db_new() will return
>> p_new->protoid=3, p_new->trans_cnt=1
>> Jan  2 14:36:29 2013 pluto[8551]: | kernel_alg_db_new()     trans[0]:
>> transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=1
>> Jan  2 14:36:29 2013 pluto[8551]: | returning new proposal from esp_info
>> Jan  2 14:36:29 2013 pluto[8551]: | sending 292 bytes for quick_outI1
>> through eth9.102:500 to RIGHT_EXT_IP:500 (using #3)
>> Jan  2 14:36:29 2013 pluto[8551]: | inserting event EVENT_RETRANSMIT,
>> timeout in 10 seconds for #3
>> Jan  2 14:36:29 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:36:29 2013 pluto[8551]: | next event EVENT_RETRANSMIT in 10
>> seconds for #3
>> Jan  2 14:36:29 2013 pluto[8551]: | next event EVENT_RETRANSMIT in 10
>> seconds for #3
>> Jan  2 14:36:29 2013 pluto[8551]: |
>> Jan  2 14:36:29 2013 pluto[8551]: | *received 324 bytes from
>> RIGHT_EXT_IP:500 on eth9.102 (port=500)
>> Jan  2 14:36:29 2013 pluto[8551]: |  processing version=1.0 packet
>> with exchange type=ISAKMP_XCHG_QUICK (32)
>> Jan  2 14:36:29 2013 pluto[8551]: | ICOOKIE:  f0 8e 7a 00  1a 12 b6 82
>> Jan  2 14:36:29 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  01 cf f6 69
>> Jan  2 14:36:29 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:36:29 2013 pluto[8551]: | v1 peer and cookies match on #3,
>> provided msgid 4a65208e vs 4a65208e
>> Jan  2 14:36:29 2013 pluto[8551]: | v1 state object #3 found, in
>> STATE_QUICK_I1
>> Jan  2 14:36:29 2013 pluto[8551]: | processing connection merkezvpn/0x2
>> Jan  2 14:36:29 2013 pluto[8551]: \"merkezvpn/0x2\" #3: ignoring
>> informational payload, type IPSEC_RESPONDER_LIFETIME msgid=8e20654a
>> Jan  2 14:36:29 2013 pluto[8551]: | started looking for secret for
>> LEFT_EXT_IP->10.6.202.3 of kind PPK_PSK
>> Jan  2 14:36:29 2013 pluto[8551]: | actually looking for secret for
>> LEFT_EXT_IP->10.6.202.3 of kind PPK_PSK
>> Jan  2 14:36:29 2013 pluto[8551]: | 1: compared key 10.6.202.3 to
>> LEFT_EXT_IP / 10.6.202.3 -> 4
>> Jan  2 14:36:29 2013 pluto[8551]: | 2: compared key LEFT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 12
>> Jan  2 14:36:29 2013 pluto[8551]: | line 2: match=12
>> Jan  2 14:36:29 2013 pluto[8551]: | best_match 0>12 best=0xb7b0adc0
>> (line=2)
>> Jan  2 14:36:29 2013 pluto[8551]: | 1: compared key RIGHT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 0
>> Jan  2 14:36:29 2013 pluto[8551]: | 2: compared key LEFT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 8
>> Jan  2 14:36:29 2013 pluto[8551]: | line 1: match=8
>> Jan  2 14:36:29 2013 pluto[8551]: | concluding with best_match=12
>> best=0xb7b0adc0 (lineno=2)
>> Jan  2 14:36:29 2013 pluto[8551]: | helper -1 doing compute dh(p2) op id:
>> 0
>> Jan  2 14:36:29 2013 pluto[8551]: | processing connection merkezvpn/0x2
>> Jan  2 14:36:29 2013 pluto[8551]: | our client is subnet 10.46.0.0/16
>> Jan  2 14:36:29 2013 pluto[8551]: | our client protocol/port is 0/0
>> Jan  2 14:36:29 2013 pluto[8551]: | peer client is subnet 192.168.2.0/24
>> Jan  2 14:36:29 2013 pluto[8551]: | peer client protocol/port is 0/0
>> Jan  2 14:36:29 2013 pluto[8551]: | install_ipsec_sa() for #3: inbound
>> and outbound
>> Jan  2 14:36:29 2013 pluto[8551]: | route owner of \"merkezvpn/0x2\"
>> unrouted: NULL; eroute owner: NULL
>> Jan  2 14:36:29 2013 pluto[8551]: | could_route called for
>> merkezvpn/0x2 (kind=CK_PERMANENT)
>> Jan  2 14:36:29 2013 pluto[8551]: | add inbound eroute
>> 192.168.2.0/24:0 --0-> 10.46.0.0/16:0 => tun.10000 at LEFT_EXT_IP
>> (raw_eroute)
>> Jan  2 14:36:29 2013 pluto[8551]: | raw_eroute result=1
>> Jan  2 14:36:29 2013 pluto[8551]: | sr for #3: unrouted
>> Jan  2 14:36:29 2013 pluto[8551]: | route owner of \"merkezvpn/0x2\"
>> unrouted: NULL; eroute owner: NULL
>> Jan  2 14:36:29 2013 pluto[8551]: | eroute_connection add eroute
>> 10.46.0.0/16:0 --0-> 192.168.2.0/24:0 => tun.0 at RIGHT_EXT_IP
>> (raw_eroute)
>> Jan  2 14:36:29 2013 pluto[8551]: | raw_eroute result=1
>> Jan  2 14:36:29 2013 pluto[8551]: | command executing up-client
>> Jan  2 14:36:29 2013 pluto[8551]: | executing up-client: 2>&1
>> PLUTO_VERB=\'up-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0x2\' PLUTO_INTERFACE=\'eth9.102\'
>> PLUTO_NEXT_HOP=\'10.46.1.5\' PLUTO_ME=\'LEFT_EXT_IP\'
>> PLUTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'10.46.0.0\' PLUTO_MY_CLIENT_MASK=\'255.255.0.0\'
>> PLUTO_MY_PORT=\'0\' PLUTO_MY_PROTOCOL=\'0\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'192.168.2.0/24\'
>> PLUTO_PEER_CLIENT_NET=\'192.168.2.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.255.0\' PLUTO_PEER_PORT=\'0\'
>> PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\' PLUTO_STACK=\'netkey\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK\'
>> PLUTO_CONN_ADDRFAMILY=\'ipv4\' PLUTO_XAUTH_USERNAME=\'\'
>> PLUTO_MY_SOURCEIP=\'10.46.1.5\' PLUTO_IS_PEER_CISCO=\'0\'
>> PLUTO_CISCO_DNS_INFO=\'\' PLUTO_CISCO_DOMAIN_INFO=\'\'
>> PLUTO_PEER_BANNER=\'\' PLUTO_NM_CONFIGURED=\'0\' ipsec _updown
>> Jan  2 14:36:29 2013 pluto[8551]: | popen(): cmd is 853 chars long
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd(   0):2>&1
>> PLUTO_VERB=\'up-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0x2\':
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd(  80):
>> PLUTO_INTERFACE=\'eth9.102\' PLUTO_NEXT_HOP=\'10.46.1.5\'
>> PLUTO_ME=\'LEFT_EXT_IP\' PL:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd(
>> 160):UTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'10.4:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 240):6.0.0\'
>> PLUTO_MY_CLIENT_MASK=\'255.255.0.0\' PLUTO_MY_PORT=\'0\'
>> PLUTO_MY_PROTOCOL=\'0:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 320):\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'192.16:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 400):8.2.0/24\'
>> PLUTO_PEER_CLIENT_NET=\'192.168.2.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.25:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 480):5.0\'
>> PLUTO_PEER_PORT=\'0\' PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\'
>> PLUTO_STACK=\'n:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 560):etkey\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK\'
>> PLU:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd(
>> 640):TO_CONN_ADDRFAMILY=\'ipv4\' PLUTO_XAUTH_USERNAME=\'\'
>> PLUTO_MY_SOURCEIP=\'10.46.1.5\' :
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd(
>> 720):PLUTO_IS_PEER_CISCO=\'0\' PLUTO_CISCO_DNS_INFO=\'\'
>> PLUTO_CISCO_DOMAIN_INFO=\'\' PLUTO:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 800):_PEER_BANNER=\'\'
>> PLUTO_NM_CONFIGURED=\'0\' ipsec _updown:
>> Jan  2 14:36:29 2013 pluto[8551]: | route_and_eroute: firewall_notified:
>> true
>> Jan  2 14:36:29 2013 pluto[8551]: | command executing prepare-client
>> Jan  2 14:36:29 2013 pluto[8551]: | executing prepare-client: 2>&1
>> PLUTO_VERB=\'prepare-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0x2\' PLUTO_INTERFACE=\'eth9.102\'
>> PLUTO_NEXT_HOP=\'10.46.1.5\' PLUTO_ME=\'LEFT_EXT_IP\'
>> PLUTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'10.46.0.0\' PLUTO_MY_CLIENT_MASK=\'255.255.0.0\'
>> PLUTO_MY_PORT=\'0\' PLUTO_MY_PROTOCOL=\'0\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'192.168.2.0/24\'
>> PLUTO_PEER_CLIENT_NET=\'192.168.2.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.255.0\' PLUTO_PEER_PORT=\'0\'
>> PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\' PLUTO_STACK=\'netkey\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK\'
>> PLUTO_CONN_ADDRFAMILY=\'ipv4\' PLUTO_XAUTH_USERNAME=\'\'
>> PLUTO_MY_SOURCEIP=\'10.46.1.5\' PLUTO_IS_PEER_CISCO=\'0\'
>> PLUTO_CISCO_DNS_INFO=\'\' PLUTO_CISCO_DOMAIN_INFO=\'\'
>> PLUTO_PEER_BANNER=\'\' PLUTO_NM_CONFIGURED=\'0\' ipsec _updown
>> Jan  2 14:36:29 2013 pluto[8551]: | popen(): cmd is 858 chars long
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd(   0):2>&1
>> PLUTO_VERB=\'prepare-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd(  80):/0x2\'
>> PLUTO_INTERFACE=\'eth9.102\' PLUTO_NEXT_HOP=\'10.46.1.5\'
>> PLUTO_ME=\'LEFT_EXT_IP:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 160):8\'
>> PLUTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 240):\'10.46.0.0\'
>> PLUTO_MY_CLIENT_MASK=\'255.255.0.0\' PLUTO_MY_PORT=\'0\'
>> PLUTO_MY_PROTOC:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 320):OL=\'0\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'1:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 400):92.168.2.0/24\'
>> PLUTO_PEER_CLIENT_NET=\'192.168.2.0\' PLUTO_PEER_CLIENT_MASK=\'255.2:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 480):55.255.0\'
>> PLUTO_PEER_PORT=\'0\' PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\'
>> PLUTO_STA:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 560):CK=\'netkey\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 640):\'
>> PLUTO_CONN_ADDRFAMILY=\'ipv4\' PLUTO_XAUTH_USERNAME=\'\'
>> PLUTO_MY_SOURCEIP=\'10.46.:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 720):1.5\'
>> PLUTO_IS_PEER_CISCO=\'0\' PLUTO_CISCO_DNS_INFO=\'\'
>> PLUTO_CISCO_DOMAIN_INFO=\'\' :
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 800):PLUTO_PEER_BANNER=\'\'
>> PLUTO_NM_CONFIGURED=\'0\' ipsec _updown:
>> Jan  2 14:36:29 2013 pluto[8551]: | command executing route-client
>> Jan  2 14:36:29 2013 pluto[8551]: | executing route-client: 2>&1
>> PLUTO_VERB=\'route-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0x2\' PLUTO_INTERFACE=\'eth9.102\'
>> PLUTO_NEXT_HOP=\'10.46.1.5\' PLUTO_ME=\'LEFT_EXT_IP\'
>> PLUTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'10.46.0.0\' PLUTO_MY_CLIENT_MASK=\'255.255.0.0\'
>> PLUTO_MY_PORT=\'0\' PLUTO_MY_PROTOCOL=\'0\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'192.168.2.0/24\'
>> PLUTO_PEER_CLIENT_NET=\'192.168.2.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.255.0\' PLUTO_PEER_PORT=\'0\'
>> PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\' PLUTO_STACK=\'netkey\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK\'
>> PLUTO_CONN_ADDRFAMILY=\'ipv4\' PLUTO_XAUTH_USERNAME=\'\'
>> PLUTO_MY_SOURCEIP=\'10.46.1.5\' PLUTO_IS_PEER_CISCO=\'0\'
>> PLUTO_CISCO_DNS_INFO=\'\' PLUTO_CISCO_DOMAIN_INFO=\'\'
>> PLUTO_PEER_BANNER=\'\' PLUTO_NM_CONFIGURED=\'0\' ipsec _updown
>> Jan  2 14:36:29 2013 pluto[8551]: | popen(): cmd is 856 chars long
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd(   0):2>&1
>> PLUTO_VERB=\'route-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd(  80):x2\'
>> PLUTO_INTERFACE=\'eth9.102\' PLUTO_NEXT_HOP=\'10.46.1.5\'
>> PLUTO_ME=\'LEFT_EXT_IP\':
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 160):
>> PLUTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'1:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 240):0.46.0.0\'
>> PLUTO_MY_CLIENT_MASK=\'255.255.0.0\' PLUTO_MY_PORT=\'0\'
>> PLUTO_MY_PROTOCOL:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 320):=\'0\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'192:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 400):.168.2.0/24\'
>> PLUTO_PEER_CLIENT_NET=\'192.168.2.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 480):.255.0\'
>> PLUTO_PEER_PORT=\'0\' PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\'
>> PLUTO_STACK:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 560):=\'netkey\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK\'
>> :
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd(
>> 640):PLUTO_CONN_ADDRFAMILY=\'ipv4\' PLUTO_XAUTH_USERNAME=\'\'
>> PLUTO_MY_SOURCEIP=\'10.46.1.:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 720):5\'
>> PLUTO_IS_PEER_CISCO=\'0\' PLUTO_CISCO_DNS_INFO=\'\'
>> PLUTO_CISCO_DOMAIN_INFO=\'\' PL:
>> Jan  2 14:36:29 2013 pluto[8551]: | cmd( 800):UTO_PEER_BANNER=\'\'
>> PLUTO_NM_CONFIGURED=\'0\' ipsec _updown:
>> Jan  2 14:36:29 2013 pluto[8551]: \"merkezvpn/0x2\" #3: route-client
>> output: /usr/libexec/ipsec/_updown.netkey: doroute `ip route replace
>> 192.168.2.0/24 via 10.46.1.5 dev lo  src 10.46.1.5\' failed (RTNETLINK
>> answers: No such process)
>> Jan  2 14:36:29 2013 pluto[8551]: | route_and_eroute: instance
>> \"merkezvpn/0x2\", setting eroute_owner {spd=0xb7b107a8,sr=0xb7b107a8}
>> to #3 (was #0) (newest_ipsec_sa=#0)
>> Jan  2 14:36:29 2013 pluto[8551]: | complete state transition with STF_OK
>> Jan  2 14:36:29 2013 pluto[8551]: \"merkezvpn/0x2\" #3: transition
>> from state STATE_QUICK_I1 to state STATE_QUICK_I2
>> Jan  2 14:36:29 2013 pluto[8551]: | sending reply packet to
>> RIGHT_EXT_IP:500 (from port 500)
>> Jan  2 14:36:29 2013 pluto[8551]: | sending 52 bytes for
>> STATE_QUICK_I1 through eth9.102:500 to RIGHT_EXT_IP:500 (using #3)
>> Jan  2 14:36:29 2013 pluto[8551]: | inserting event EVENT_SA_REPLACE,
>> timeout in 85438 seconds for #3
>> Jan  2 14:36:29 2013 pluto[8551]: \"merkezvpn/0x2\" #3:
>> STATE_QUICK_I2: sent QI2, IPsec SA established tunnel mode
>> {ESP=>0x58709341 <0x66e7526f xfrm=3DES_0-HMAC_MD5 NATOA=none NATD=none
>> DPD=none}
>> Jan  2 14:36:29 2013 pluto[8551]: | modecfg pull: noquirk policy:push
>> not-client
>> Jan  2 14:36:29 2013 pluto[8551]: | phase 1 is done, looking for phase
>> 2 to unpend
>> Jan  2 14:36:29 2013 pluto[8551]: | complete state transition with
>> STF_INLINE
>> Jan  2 14:36:29 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:36:29 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 50
>> seconds
>> Jan  2 14:36:29 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 50
>> seconds
>> Jan  2 14:37:06 2013 pluto[8551]: |
>> Jan  2 14:37:06 2013 pluto[8551]: | *received whack message
>> Jan  2 14:37:06 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:37:06 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 13
>> seconds
>> Jan  2 14:37:06 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 13
>> seconds
>> Jan  2 14:37:19 2013 pluto[8551]: |
>> Jan  2 14:37:19 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 0
>> seconds
>> Jan  2 14:37:19 2013 pluto[8551]: | *time to handle event
>> Jan  2 14:37:19 2013 pluto[8551]: | handling event EVENT_PENDING_DDNS
>> Jan  2 14:37:19 2013 pluto[8551]: | event after this is
>> EVENT_PENDING_PHASE2 in 60 seconds
>> Jan  2 14:37:19 2013 pluto[8551]: | inserting event
>> EVENT_PENDING_DDNS, timeout in 60 seconds
>> Jan  2 14:37:19 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 60
>> seconds
>> Jan  2 14:37:30 2013 smokeping[7697]: Alert someloss is active for
>> Default.vpn1
>> Jan  2 14:37:30 2013 smokeping[7697]: Alert someloss is active for
>> Default.main
>> Jan  2 14:37:30 2013 smokeping[7697]: Alert someloss is active for
>> Default.vpn2
>> Jan  2 14:38:06 2013 pluto[8551]: |
>> Jan  2 14:38:06 2013 pluto[8551]: | *received whack message
>> Jan  2 14:38:06 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:38:06 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 13
>> seconds
>> Jan  2 14:38:06 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 13
>> seconds
>> Jan  2 14:38:19 2013 pluto[8551]: |
>> Jan  2 14:38:19 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 0
>> seconds
>> Jan  2 14:38:19 2013 pluto[8551]: | *time to handle event
>> Jan  2 14:38:19 2013 pluto[8551]: | handling event EVENT_PENDING_DDNS
>> Jan  2 14:38:19 2013 pluto[8551]: | event after this is
>> EVENT_PENDING_PHASE2 in 0 seconds
>> Jan  2 14:38:19 2013 pluto[8551]: | inserting event
>> EVENT_PENDING_DDNS, timeout in 60 seconds
>> Jan  2 14:38:19 2013 pluto[8551]: | handling event EVENT_PENDING_PHASE2
>> Jan  2 14:38:19 2013 pluto[8551]: | event after this is
>> EVENT_PENDING_DDNS in 60 seconds
>> Jan  2 14:38:19 2013 pluto[8551]: | inserting event
>> EVENT_PENDING_PHASE2, timeout in 120 seconds
>> Jan  2 14:38:19 2013 pluto[8551]: | pending review: connection
>> \"merkezvpn/0x2\" checked
>> Jan  2 14:38:19 2013 pluto[8551]: | pending review: connection
>> \"merkezvpn/0x1\" checked
>> Jan  2 14:38:19 2013 pluto[8551]: | pending review: connection
>> \"passthru\" has no negotiated policy, skipped
>> Jan  2 14:38:19 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 60
>> seconds
>> Jan  2 14:39:04 2013 pluto[8551]: |
>> Jan  2 14:39:04 2013 pluto[8551]: | *received whack message
>> Jan  2 14:39:04 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:39:04 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 15
>> seconds
>> Jan  2 14:39:04 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 15
>> seconds
>> Jan  2 14:39:08 2013 pluto[8551]: |
>> Jan  2 14:39:08 2013 pluto[8551]: | *received whack message
>> Jan  2 14:39:08 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:39:08 2013 pluto[8551]: \"merkezvpn/0x1\": terminating SAs
>> using this connection
>> Jan  2 14:39:08 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:39:08 2013 pluto[8551]: \"merkezvpn/0x1\" #2: deleting state
>> (STATE_QUICK_I2)
>> Jan  2 14:39:08 2013 pluto[8551]: | deleting state #2
>> Jan  2 14:39:08 2013 pluto[8551]: | sending 68 bytes for delete notify
>> through eth9.102:500 to RIGHT_EXT_IP:500 (using #1)
>> Jan  2 14:39:08 2013 pluto[8551]: | command executing down-client
>> Jan  2 14:39:08 2013 pluto[8551]: | executing down-client: 2>&1
>> PLUTO_VERB=\'down-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0x1\' PLUTO_INTERFACE=\'eth9.102\'
>> PLUTO_NEXT_HOP=\'10.46.1.5\' PLUTO_ME=\'LEFT_EXT_IP\'
>> PLUTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'10.46.0.0\' PLUTO_MY_CLIENT_MASK=\'255.255.0.0\'
>> PLUTO_MY_PORT=\'0\' PLUTO_MY_PROTOCOL=\'0\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'10.6.0.0/16\' PLUTO_PEER_CLIENT_NET=\'10.6.0.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.0.0\' PLUTO_PEER_PORT=\'0\'
>> PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\' PLUTO_STACK=\'netkey\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+IKEv2ALLOW+SAREFTRACK\'
>> PLUTO_CONN_ADDRFAMILY=\'ipv4\' PLUTO_XAUTH_USERNAME=\'\'
>> PLUTO_MY_SOURCEIP=\'10.46.1.5\' PLUTO_IS_PEER_CISCO=\'0\'
>> PLUTO_CISCO_DNS_INFO=\'\' PLUTO_CISCO_DOMAIN_INFO=\'\'
>> PLUTO_PEER_BANNER=\'\' PLUTO_NM_CONFIGURED=\'0\' ipsec _updown
>> Jan  2 14:39:08 2013 pluto[8551]: | popen(): cmd is 844 chars long
>> Jan  2 14:39:08 2013 pluto[8551]: | cmd(   0):2>&1
>> PLUTO_VERB=\'down-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0x:
>> Jan  2 14:39:08 2013 pluto[8551]: | cmd(  80):1\'
>> PLUTO_INTERFACE=\'eth9.102\' PLUTO_NEXT_HOP=\'10.46.1.5\'
>> PLUTO_ME=\'LEFT_EXT_IP\' :
>> Jan  2 14:39:08 2013 pluto[8551]: | cmd(
>> 160):PLUTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'10:
>> Jan  2 14:39:08 2013 pluto[8551]: | cmd( 240):.46.0.0\'
>> PLUTO_MY_CLIENT_MASK=\'255.255.0.0\' PLUTO_MY_PORT=\'0\'
>> PLUTO_MY_PROTOCOL=:
>> Jan  2 14:39:08 2013 pluto[8551]: | cmd( 320):\'0\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'10.6:
>> Jan  2 14:39:08 2013 pluto[8551]: | cmd( 400):.0.0/16\'
>> PLUTO_PEER_CLIENT_NET=\'10.6.0.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.0.0\' P:
>> Jan  2 14:39:08 2013 pluto[8551]: | cmd( 480):LUTO_PEER_PORT=\'0\'
>> PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\' PLUTO_STACK=\'netkey\':
>> Jan  2 14:39:08 2013 pluto[8551]: | cmd( 560):
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+IKEv2ALLOW+SAREFTRACK\'
>> PLUTO_CONN_A:
>> Jan  2 14:39:08 2013 pluto[8551]: | cmd( 640):DDRFAMILY=\'ipv4\'
>> PLUTO_XAUTH_USERNAME=\'\' PLUTO_MY_SOURCEIP=\'10.46.1.5\' PLUTO_IS_:
>> Jan  2 14:39:08 2013 pluto[8551]: | cmd( 720):PEER_CISCO=\'0\'
>> PLUTO_CISCO_DNS_INFO=\'\' PLUTO_CISCO_DOMAIN_INFO=\'\' PLUTO_PEER_BAN:
>> Jan  2 14:39:08 2013 pluto[8551]: | cmd( 800):NER=\'\'
>> PLUTO_NM_CONFIGURED=\'0\' ipsec _updown:
>> Jan  2 14:39:08 2013 pluto[8551]: | request to replace with shunt a
>> prospective erouted policy with netkey kernel --- experimental
>> Jan  2 14:39:08 2013 pluto[8551]: | delete inbound eroute
>> 10.6.0.0/16:0 --0-> 10.46.0.0/16:0 => unk255.10000 at LEFT_EXT_IP
>> (raw_eroute)
>> Jan  2 14:39:08 2013 pluto[8551]: | raw_eroute result=1
>> Jan  2 14:39:08 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:39:08 2013 pluto[8551]: \"merkezvpn/0x1\" #1: deleting state
>> (STATE_MAIN_I4)
>> Jan  2 14:39:08 2013 pluto[8551]: | deleting state #1
>> Jan  2 14:39:08 2013 pluto[8551]: | sending 76 bytes for delete notify
>> through eth9.102:500 to RIGHT_EXT_IP:500 (using #1)
>> Jan  2 14:39:08 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:39:08 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 11
>> seconds
>> Jan  2 14:39:08 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 11
>> seconds
>> Jan  2 14:39:08 2013 pluto[8551]: |
>> Jan  2 14:39:08 2013 pluto[8551]: | *received 84 bytes from
>> RIGHT_EXT_IP:500 on eth9.102 (port=500)
>> Jan  2 14:39:08 2013 pluto[8551]: |  processing version=1.0 packet
>> with exchange type=ISAKMP_XCHG_INFO (5)
>> Jan  2 14:39:08 2013 pluto[8551]: | ICOOKIE:  f0 8e 7a 00  1a 12 b6 82
>> Jan  2 14:39:08 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  01 cf f6 69
>> Jan  2 14:39:08 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:39:08 2013 pluto[8551]: | peer and cookies match on #3,
>> provided msgid 00000000 vs 4a65208e/00000000
>> Jan  2 14:39:08 2013 pluto[8551]: | p15 state object not found
>> Jan  2 14:39:08 2013 pluto[8551]: | ICOOKIE:  f0 8e 7a 00  1a 12 b6 82
>> Jan  2 14:39:08 2013 pluto[8551]: | RCOOKIE:  00 00 00 00  00 00 00 00
>> Jan  2 14:39:08 2013 pluto[8551]: | state hash entry 24
>> Jan  2 14:39:08 2013 pluto[8551]: | v1 state object not found
>> Jan  2 14:39:08 2013 pluto[8551]: packet from RIGHT_EXT_IP:500:
>> Informational Exchange is for an unknown (expired?) SA with
>> MSGID:0x6deab37d
>> Jan  2 14:39:08 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:39:08 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 11
>> seconds
>> Jan  2 14:39:08 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 11
>> seconds
>> Jan  2 14:39:09 2013 pluto[8551]: |
>> Jan  2 14:39:09 2013 pluto[8551]: | *received whack message
>> Jan  2 14:39:09 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:39:09 2013 pluto[8551]: | kernel_alg_db_new() will return
>> p_new->protoid=3, p_new->trans_cnt=1
>> Jan  2 14:39:09 2013 pluto[8551]: | kernel_alg_db_new()     trans[0]:
>> transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=1
>> Jan  2 14:39:09 2013 pluto[8551]: | returning new proposal from esp_info
>> Jan  2 14:39:09 2013 pluto[8551]: | creating state object #4 at 0xb7b10fc8
>> Jan  2 14:39:09 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:39:09 2013 pluto[8551]: | ICOOKIE:  02 d4 a3 f4  91 a0 7e 97
>> Jan  2 14:39:09 2013 pluto[8551]: | RCOOKIE:  00 00 00 00  00 00 00 00
>> Jan  2 14:39:09 2013 pluto[8551]: | state hash entry 27
>> Jan  2 14:39:09 2013 pluto[8551]: | inserting state object #4
>> Jan  2 14:39:09 2013 pluto[8551]: | inserting event EVENT_SO_DISCARD,
>> timeout in 0 seconds for #4
>> Jan  2 14:39:09 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:39:09 2013 pluto[8551]: | Queuing pending Quick Mode with
>> RIGHT_EXT_IP \"merkezvpn/0x1\"
>> Jan  2 14:39:09 2013 pluto[8551]: \"merkezvpn/0x1\" #4: initiating Main
>> Mode
>> Jan  2 14:39:09 2013 pluto[8551]: | sending 120 bytes for main_outI1
>> through eth9.102:500 to RIGHT_EXT_IP:500 (using #4)
>> Jan  2 14:39:09 2013 pluto[8551]: | inserting event EVENT_RETRANSMIT,
>> timeout in 10 seconds for #4
>> Jan  2 14:39:09 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:39:09 2013 pluto[8551]: | next event EVENT_RETRANSMIT in 10
>> seconds for #4
>> Jan  2 14:39:09 2013 pluto[8551]: | next event EVENT_RETRANSMIT in 10
>> seconds for #4
>> Jan  2 14:39:09 2013 pluto[8551]: |
>> Jan  2 14:39:09 2013 pluto[8551]: | *received 84 bytes from
>> RIGHT_EXT_IP:500 on eth9.102 (port=500)
>> Jan  2 14:39:09 2013 pluto[8551]: |  processing version=1.0 packet
>> with exchange type=ISAKMP_XCHG_IDPROT (2)
>> Jan  2 14:39:09 2013 pluto[8551]: | ICOOKIE:  02 d4 a3 f4  91 a0 7e 97
>> Jan  2 14:39:09 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  a5 36 cb b0
>> Jan  2 14:39:09 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:39:09 2013 pluto[8551]: | v1 state object not found
>> Jan  2 14:39:09 2013 pluto[8551]: | ICOOKIE:  02 d4 a3 f4  91 a0 7e 97
>> Jan  2 14:39:09 2013 pluto[8551]: | RCOOKIE:  00 00 00 00  00 00 00 00
>> Jan  2 14:39:09 2013 pluto[8551]: | state hash entry 27
>> Jan  2 14:39:09 2013 pluto[8551]: | v1 peer and cookies match on #4,
>> provided msgid 00000000 vs 00000000
>> Jan  2 14:39:09 2013 pluto[8551]: | v1 state object #4 found, in
>> STATE_MAIN_I1
>> Jan  2 14:39:09 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:39:09 2013 pluto[8551]: | started looking for secret for
>> LEFT_EXT_IP->10.6.202.3 of kind PPK_PSK
>> Jan  2 14:39:09 2013 pluto[8551]: | actually looking for secret for
>> LEFT_EXT_IP->10.6.202.3 of kind PPK_PSK
>> Jan  2 14:39:09 2013 pluto[8551]: | 1: compared key 10.6.202.3 to
>> LEFT_EXT_IP / 10.6.202.3 -> 4
>> Jan  2 14:39:09 2013 pluto[8551]: | 2: compared key LEFT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 12
>> Jan  2 14:39:09 2013 pluto[8551]: | line 2: match=12
>> Jan  2 14:39:09 2013 pluto[8551]: | best_match 0>12 best=0xb7b0adc0
>> (line=2)
>> Jan  2 14:39:09 2013 pluto[8551]: | 1: compared key RIGHT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 0
>> Jan  2 14:39:09 2013 pluto[8551]: | 2: compared key LEFT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 8
>> Jan  2 14:39:09 2013 pluto[8551]: | line 1: match=8
>> Jan  2 14:39:09 2013 pluto[8551]: | concluding with best_match=12
>> best=0xb7b0adc0 (lineno=2)
>> Jan  2 14:39:09 2013 pluto[8551]: | helper -1 doing build_kenonce op id: 0
>> Jan  2 14:39:09 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:39:09 2013 pluto[8551]: | ICOOKIE:  02 d4 a3 f4  91 a0 7e 97
>> Jan  2 14:39:09 2013 pluto[8551]: | RCOOKIE:  00 00 00 00  00 00 00 00
>> Jan  2 14:39:09 2013 pluto[8551]: | state hash entry 27
>> Jan  2 14:39:09 2013 pluto[8551]: | ICOOKIE:  02 d4 a3 f4  91 a0 7e 97
>> Jan  2 14:39:09 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  a5 36 cb b0
>> Jan  2 14:39:09 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:39:09 2013 pluto[8551]: | inserting state object #4
>> Jan  2 14:39:09 2013 pluto[8551]: | complete state transition with STF_OK
>> Jan  2 14:39:09 2013 pluto[8551]: \"merkezvpn/0x1\" #4: transition
>> from state STATE_MAIN_I1 to state STATE_MAIN_I2
>> Jan  2 14:39:09 2013 pluto[8551]: | sending reply packet to
>> RIGHT_EXT_IP:500 (from port 500)
>> Jan  2 14:39:09 2013 pluto[8551]: | sending 180 bytes for
>> STATE_MAIN_I1 through eth9.102:500 to RIGHT_EXT_IP:500 (using #4)
>> Jan  2 14:39:09 2013 pluto[8551]: | inserting event EVENT_RETRANSMIT,
>> timeout in 10 seconds for #4
>> Jan  2 14:39:09 2013 pluto[8551]: \"merkezvpn/0x1\" #4: STATE_MAIN_I2:
>> sent MI2, expecting MR2
>> Jan  2 14:39:09 2013 pluto[8551]: | modecfg pull: noquirk policy:push
>> not-client
>> Jan  2 14:39:09 2013 pluto[8551]: | phase 1 is done, looking for phase
>> 2 to unpend
>> Jan  2 14:39:09 2013 pluto[8551]: | complete state transition with
>> STF_INLINE
>> Jan  2 14:39:09 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:39:09 2013 pluto[8551]: | next event EVENT_RETRANSMIT in 10
>> seconds for #4
>> Jan  2 14:39:09 2013 pluto[8551]: | next event EVENT_RETRANSMIT in 10
>> seconds for #4
>> Jan  2 14:39:09 2013 pluto[8551]: |
>> Jan  2 14:39:09 2013 pluto[8551]: | *received 256 bytes from
>> RIGHT_EXT_IP:500 on eth9.102 (port=500)
>> Jan  2 14:39:09 2013 pluto[8551]: |  processing version=1.0 packet
>> with exchange type=ISAKMP_XCHG_IDPROT (2)
>> Jan  2 14:39:09 2013 pluto[8551]: | ICOOKIE:  02 d4 a3 f4  91 a0 7e 97
>> Jan  2 14:39:09 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  a5 36 cb b0
>> Jan  2 14:39:09 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:39:09 2013 pluto[8551]: | v1 peer and cookies match on #4,
>> provided msgid 00000000 vs 00000000
>> Jan  2 14:39:09 2013 pluto[8551]: | v1 state object #4 found, in
>> STATE_MAIN_I2
>> Jan  2 14:39:09 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:39:09 2013 pluto[8551]: \"merkezvpn/0x1\" #4: received
>> Vendor ID payload [Cisco-Unity]
>> Jan  2 14:39:09 2013 pluto[8551]: \"merkezvpn/0x1\" #4: received
>> Vendor ID payload [Dead Peer Detection]
>> Jan  2 14:39:09 2013 pluto[8551]: \"merkezvpn/0x1\" #4: ignoring
>> unknown Vendor ID payload [0945ede6a537cbb0dd3f71085a179386]
>> Jan  2 14:39:09 2013 pluto[8551]: \"merkezvpn/0x1\" #4: received
>> Vendor ID payload [XAUTH]
>> Jan  2 14:39:09 2013 pluto[8551]: | started looking for secret for
>> LEFT_EXT_IP->10.6.202.3 of kind PPK_PSK
>> Jan  2 14:39:09 2013 pluto[8551]: | actually looking for secret for
>> LEFT_EXT_IP->10.6.202.3 of kind PPK_PSK
>> Jan  2 14:39:09 2013 pluto[8551]: | 1: compared key 10.6.202.3 to
>> LEFT_EXT_IP / 10.6.202.3 -> 4
>> Jan  2 14:39:09 2013 pluto[8551]: | 2: compared key LEFT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 12
>> Jan  2 14:39:09 2013 pluto[8551]: | line 2: match=12
>> Jan  2 14:39:09 2013 pluto[8551]: | best_match 0>12 best=0xb7b0adc0
>> (line=2)
>> Jan  2 14:39:09 2013 pluto[8551]: | 1: compared key RIGHT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 0
>> Jan  2 14:39:09 2013 pluto[8551]: | 2: compared key LEFT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 8
>> Jan  2 14:39:09 2013 pluto[8551]: | line 1: match=8
>> Jan  2 14:39:09 2013 pluto[8551]: | concluding with best_match=12
>> best=0xb7b0adc0 (lineno=2)
>> Jan  2 14:39:09 2013 pluto[8551]: | parent1 type: 7 group: 2 len: 2680
>> Jan  2 14:39:09 2013 pluto[8551]: | helper -1 doing compute dh+iv op id: 0
>> Jan  2 14:39:09 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:39:09 2013 pluto[8551]: | thinking about whether to send my
>> certificate:
>> Jan  2 14:39:09 2013 pluto[8551]: |   I have RSA key:
>> OAKLEY_PRESHARED_KEY cert.type: CERT_NONE
>> Jan  2 14:39:09 2013 pluto[8551]: |   sendcert: CERT_ALWAYSSEND and I
>> did not get a certificate request
>> Jan  2 14:39:09 2013 pluto[8551]: |   so do not send cert.
>> Jan  2 14:39:09 2013 pluto[8551]: | I did not send a certificate
>> because digital signatures are not being used. (PSK)
>> Jan  2 14:39:09 2013 pluto[8551]: |  I am not sending a certificate
>> request
>> Jan  2 14:39:09 2013 pluto[8551]: | complete state transition with STF_OK
>> Jan  2 14:39:09 2013 pluto[8551]: \"merkezvpn/0x1\" #4: transition
>> from state STATE_MAIN_I2 to state STATE_MAIN_I3
>> Jan  2 14:39:09 2013 pluto[8551]: | sending reply packet to
>> RIGHT_EXT_IP:500 (from port 500)
>> Jan  2 14:39:09 2013 pluto[8551]: | sending 60 bytes for STATE_MAIN_I2
>> through eth9.102:500 to RIGHT_EXT_IP:500 (using #4)
>> Jan  2 14:39:09 2013 pluto[8551]: | inserting event EVENT_RETRANSMIT,
>> timeout in 10 seconds for #4
>> Jan  2 14:39:09 2013 pluto[8551]: \"merkezvpn/0x1\" #4: STATE_MAIN_I3:
>> sent MI3, expecting MR3
>> Jan  2 14:39:09 2013 pluto[8551]: | modecfg pull: noquirk policy:push
>> not-client
>> Jan  2 14:39:09 2013 pluto[8551]: | phase 1 is done, looking for phase
>> 2 to unpend
>> Jan  2 14:39:09 2013 pluto[8551]: | complete state transition with
>> STF_INLINE
>> Jan  2 14:39:09 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:39:09 2013 pluto[8551]: | next event EVENT_RETRANSMIT in 10
>> seconds for #4
>> Jan  2 14:39:09 2013 pluto[8551]: | next event EVENT_RETRANSMIT in 10
>> seconds for #4
>> Jan  2 14:39:09 2013 pluto[8551]: |
>> Jan  2 14:39:09 2013 pluto[8551]: | *received 68 bytes from
>> RIGHT_EXT_IP:500 on eth9.102 (port=500)
>> Jan  2 14:39:09 2013 pluto[8551]: |  processing version=1.0 packet
>> with exchange type=ISAKMP_XCHG_IDPROT (2)
>> Jan  2 14:39:09 2013 pluto[8551]: | ICOOKIE:  02 d4 a3 f4  91 a0 7e 97
>> Jan  2 14:39:09 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  a5 36 cb b0
>> Jan  2 14:39:09 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:39:09 2013 pluto[8551]: | v1 peer and cookies match on #4,
>> provided msgid 00000000 vs 00000000
>> Jan  2 14:39:09 2013 pluto[8551]: | v1 state object #4 found, in
>> STATE_MAIN_I3
>> Jan  2 14:39:09 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:39:09 2013 pluto[8551]: \"merkezvpn/0x1\" #4: Main mode peer
>> ID is ID_IPV4_ADDR: \'10.6.202.3\'
>> Jan  2 14:39:09 2013 pluto[8551]: | complete state transition with STF_OK
>> Jan  2 14:39:09 2013 pluto[8551]: \"merkezvpn/0x1\" #4: transition
>> from state STATE_MAIN_I3 to state STATE_MAIN_I4
>> Jan  2 14:39:09 2013 pluto[8551]: | inserting event EVENT_SA_REPLACE,
>> timeout in 85429 seconds for #4
>> Jan  2 14:39:09 2013 pluto[8551]: \"merkezvpn/0x1\" #4: STATE_MAIN_I4:
>> ISAKMP SA established {auth=OAKLEY_PRESHARED_KEY
>> cipher=oakley_3des_cbc_192 prf=oakley_md5 group=modp1024}
>> Jan  2 14:39:09 2013 pluto[8551]: | modecfg pull: noquirk policy:push
>> not-client
>> Jan  2 14:39:09 2013 pluto[8551]: | phase 1 is done, looking for phase
>> 2 to unpend
>> Jan  2 14:39:09 2013 pluto[8551]: | unqueuing pending Quick Mode with
>> RIGHT_EXT_IP \"merkezvpn/0x1\" import:admin initiate
>> Jan  2 14:39:09 2013 pluto[8551]: | duplicating state object #4
>> Jan  2 14:39:09 2013 pluto[8551]: | creating state object #5 at 0xb7b25228
>> Jan  2 14:39:09 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:39:09 2013 pluto[8551]: | ICOOKIE:  02 d4 a3 f4  91 a0 7e 97
>> Jan  2 14:39:09 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  a5 36 cb b0
>> Jan  2 14:39:09 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:39:09 2013 pluto[8551]: | inserting state object #5
>> Jan  2 14:39:09 2013 pluto[8551]: | inserting event EVENT_SO_DISCARD,
>> timeout in 0 seconds for #5
>> Jan  2 14:39:09 2013 pluto[8551]: \"merkezvpn/0x1\" #5: initiating
>> Quick Mode PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK {using
>> isakmp#4 msgid:52e57021 proposal=3DES(3)_192-MD5(1)_096
>> pfsgroup=OAKLEY_GROUP_MODP1024}
>> Jan  2 14:39:09 2013 pluto[8551]: | helper -1 doing build_kenonce op id: 0
>> Jan  2 14:39:09 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:39:09 2013 pluto[8551]: | kernel_alg_db_new() will return
>> p_new->protoid=3, p_new->trans_cnt=1
>> Jan  2 14:39:09 2013 pluto[8551]: | kernel_alg_db_new()     trans[0]:
>> transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=1
>> Jan  2 14:39:09 2013 pluto[8551]: | returning new proposal from esp_info
>> Jan  2 14:39:09 2013 pluto[8551]: | sending 292 bytes for quick_outI1
>> through eth9.102:500 to RIGHT_EXT_IP:500 (using #5)
>> Jan  2 14:39:09 2013 pluto[8551]: | inserting event EVENT_RETRANSMIT,
>> timeout in 10 seconds for #5
>> Jan  2 14:39:09 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:39:09 2013 pluto[8551]: | next event EVENT_RETRANSMIT in 10
>> seconds for #5
>> Jan  2 14:39:09 2013 pluto[8551]: | next event EVENT_RETRANSMIT in 10
>> seconds for #5
>> Jan  2 14:39:09 2013 pluto[8551]: |
>> Jan  2 14:39:09 2013 pluto[8551]: | *received 324 bytes from
>> RIGHT_EXT_IP:500 on eth9.102 (port=500)
>> Jan  2 14:39:09 2013 pluto[8551]: |  processing version=1.0 packet
>> with exchange type=ISAKMP_XCHG_QUICK (32)
>> Jan  2 14:39:09 2013 pluto[8551]: | ICOOKIE:  02 d4 a3 f4  91 a0 7e 97
>> Jan  2 14:39:09 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  a5 36 cb b0
>> Jan  2 14:39:09 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:39:09 2013 pluto[8551]: | v1 peer and cookies match on #5,
>> provided msgid 2170e552 vs 2170e552
>> Jan  2 14:39:09 2013 pluto[8551]: | v1 state object #5 found, in
>> STATE_QUICK_I1
>> Jan  2 14:39:09 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:39:09 2013 pluto[8551]: \"merkezvpn/0x1\" #5: ignoring
>> informational payload, type IPSEC_RESPONDER_LIFETIME msgid=52e57021
>> Jan  2 14:39:09 2013 pluto[8551]: | started looking for secret for
>> LEFT_EXT_IP->10.6.202.3 of kind PPK_PSK
>> Jan  2 14:39:09 2013 pluto[8551]: | actually looking for secret for
>> LEFT_EXT_IP->10.6.202.3 of kind PPK_PSK
>> Jan  2 14:39:09 2013 pluto[8551]: | 1: compared key 10.6.202.3 to
>> LEFT_EXT_IP / 10.6.202.3 -> 4
>> Jan  2 14:39:09 2013 pluto[8551]: | 2: compared key LEFT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 12
>> Jan  2 14:39:09 2013 pluto[8551]: | line 2: match=12
>> Jan  2 14:39:09 2013 pluto[8551]: | best_match 0>12 best=0xb7b0adc0
>> (line=2)
>> Jan  2 14:39:09 2013 pluto[8551]: | 1: compared key RIGHT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 0
>> Jan  2 14:39:09 2013 pluto[8551]: | 2: compared key LEFT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 8
>> Jan  2 14:39:09 2013 pluto[8551]: | line 1: match=8
>> Jan  2 14:39:09 2013 pluto[8551]: | concluding with best_match=12
>> best=0xb7b0adc0 (lineno=2)
>> Jan  2 14:39:09 2013 pluto[8551]: | helper -1 doing compute dh(p2) op id:
>> 0
>> Jan  2 14:39:09 2013 pluto[8551]: | processing connection merkezvpn/0x1
>> Jan  2 14:39:09 2013 pluto[8551]: | our client is subnet 10.46.0.0/16
>> Jan  2 14:39:09 2013 pluto[8551]: | our client protocol/port is 0/0
>> Jan  2 14:39:09 2013 pluto[8551]: | peer client is subnet 10.6.0.0/16
>> Jan  2 14:39:09 2013 pluto[8551]: | peer client protocol/port is 0/0
>> Jan  2 14:39:09 2013 pluto[8551]: | install_ipsec_sa() for #5: inbound
>> and outbound
>> Jan  2 14:39:09 2013 pluto[8551]: | route owner of \"merkezvpn/0x1\"
>> prospective erouted: self; eroute owner: self
>> Jan  2 14:39:09 2013 pluto[8551]: | could_route called for
>> merkezvpn/0x1 (kind=CK_PERMANENT)
>> Jan  2 14:39:09 2013 pluto[8551]: | add inbound eroute 10.6.0.0/16:0
>> --0-> 10.46.0.0/16:0 => tun.10000 at LEFT_EXT_IP (raw_eroute)
>> Jan  2 14:39:09 2013 pluto[8551]: | raw_eroute result=1
>> Jan  2 14:39:09 2013 pluto[8551]: | sr for #5: prospective erouted
>> Jan  2 14:39:09 2013 pluto[8551]: | route owner of \"merkezvpn/0x1\"
>> prospective erouted: self; eroute owner: self
>> Jan  2 14:39:09 2013 pluto[8551]: | eroute_connection replace eroute
>> 10.46.0.0/16:0 --0-> 10.6.0.0/16:0 => tun.0 at RIGHT_EXT_IP (raw_eroute)
>> Jan  2 14:39:09 2013 pluto[8551]: | raw_eroute result=1
>> Jan  2 14:39:09 2013 pluto[8551]: | command executing up-client
>> Jan  2 14:39:09 2013 pluto[8551]: | executing up-client: 2>&1
>> PLUTO_VERB=\'up-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0x1\' PLUTO_INTERFACE=\'eth9.102\'
>> PLUTO_NEXT_HOP=\'10.46.1.5\' PLUTO_ME=\'LEFT_EXT_IP\'
>> PLUTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'10.46.0.0\' PLUTO_MY_CLIENT_MASK=\'255.255.0.0\'
>> PLUTO_MY_PORT=\'0\' PLUTO_MY_PROTOCOL=\'0\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'10.6.0.0/16\' PLUTO_PEER_CLIENT_NET=\'10.6.0.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.0.0\' PLUTO_PEER_PORT=\'0\'
>> PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\' PLUTO_STACK=\'netkey\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK\'
>> PLUTO_CONN_ADDRFAMILY=\'ipv4\' PLUTO_XAUTH_USERNAME=\'\'
>> PLUTO_MY_SOURCEIP=\'10.46.1.5\' PLUTO_IS_PEER_CISCO=\'0\'
>> PLUTO_CISCO_DNS_INFO=\'\' PLUTO_CISCO_DOMAIN_INFO=\'\'
>> PLUTO_PEER_BANNER=\'\' PLUTO_NM_CONFIGURED=\'0\' ipsec _updown
>> Jan  2 14:39:09 2013 pluto[8551]: | popen(): cmd is 845 chars long
>> Jan  2 14:39:09 2013 pluto[8551]: | cmd(   0):2>&1
>> PLUTO_VERB=\'up-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0x1\':
>> Jan  2 14:39:09 2013 pluto[8551]: | cmd(  80):
>> PLUTO_INTERFACE=\'eth9.102\' PLUTO_NEXT_HOP=\'10.46.1.5\'
>> PLUTO_ME=\'LEFT_EXT_IP\' PL:
>> Jan  2 14:39:09 2013 pluto[8551]: | cmd(
>> 160):UTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'10.4:
>> Jan  2 14:39:09 2013 pluto[8551]: | cmd( 240):6.0.0\'
>> PLUTO_MY_CLIENT_MASK=\'255.255.0.0\' PLUTO_MY_PORT=\'0\'
>> PLUTO_MY_PROTOCOL=\'0:
>> Jan  2 14:39:09 2013 pluto[8551]: | cmd( 320):\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'10.6.0:
>> Jan  2 14:39:09 2013 pluto[8551]: | cmd( 400):.0/16\'
>> PLUTO_PEER_CLIENT_NET=\'10.6.0.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.0.0\' PLU:
>> Jan  2 14:39:09 2013 pluto[8551]: | cmd( 480):TO_PEER_PORT=\'0\'
>> PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\' PLUTO_STACK=\'netkey\'  :
>> Jan  2 14:39:09 2013 pluto[8551]: | cmd( 560):
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK\'
>> PLUTO_CONN_:
>> Jan  2 14:39:09 2013 pluto[8551]: | cmd( 640):ADDRFAMILY=\'ipv4\'
>> PLUTO_XAUTH_USERNAME=\'\' PLUTO_MY_SOURCEIP=\'10.46.1.5\' PLUTO_IS:
>> Jan  2 14:39:09 2013 pluto[8551]: | cmd( 720):_PEER_CISCO=\'0\'
>> PLUTO_CISCO_DNS_INFO=\'\' PLUTO_CISCO_DOMAIN_INFO=\'\' PLUTO_PEER_BA:
>> Jan  2 14:39:09 2013 pluto[8551]: | cmd( 800):NNER=\'\'
>> PLUTO_NM_CONFIGURED=\'0\' ipsec _updown:
>> Jan  2 14:39:09 2013 pluto[8551]: | route_and_eroute: firewall_notified:
>> true
>> Jan  2 14:39:09 2013 pluto[8551]: | route_and_eroute: instance
>> \"merkezvpn/0x1\", setting eroute_owner {spd=0xb7b0fa20,sr=0xb7b0fa20}
>> to #5 (was #0) (newest_ipsec_sa=#0)
>> Jan  2 14:39:09 2013 pluto[8551]: | complete state transition with STF_OK
>> Jan  2 14:39:09 2013 pluto[8551]: \"merkezvpn/0x1\" #5: transition
>> from state STATE_QUICK_I1 to state STATE_QUICK_I2
>> Jan  2 14:39:09 2013 pluto[8551]: | sending reply packet to
>> RIGHT_EXT_IP:500 (from port 500)
>> Jan  2 14:39:09 2013 pluto[8551]: | sending 52 bytes for
>> STATE_QUICK_I1 through eth9.102:500 to RIGHT_EXT_IP:500 (using #5)
>> Jan  2 14:39:09 2013 pluto[8551]: | inserting event EVENT_SA_REPLACE,
>> timeout in 85368 seconds for #5
>> Jan  2 14:39:09 2013 pluto[8551]: \"merkezvpn/0x1\" #5:
>> STATE_QUICK_I2: sent QI2, IPsec SA established tunnel mode
>> {ESP=>0x45503a95 <0x42e7ce0d xfrm=3DES_0-HMAC_MD5 NATOA=none NATD=none
>> DPD=none}
>> Jan  2 14:39:09 2013 pluto[8551]: | modecfg pull: noquirk policy:push
>> not-client
>> Jan  2 14:39:09 2013 pluto[8551]: | phase 1 is done, looking for phase
>> 2 to unpend
>> Jan  2 14:39:09 2013 pluto[8551]: | complete state transition with
>> STF_INLINE
>> Jan  2 14:39:09 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:39:09 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 10
>> seconds
>> Jan  2 14:39:09 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 10
>> seconds
>> Jan  2 14:39:19 2013 pluto[8551]: |
>> Jan  2 14:39:19 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 0
>> seconds
>> Jan  2 14:39:19 2013 pluto[8551]: | *time to handle event
>> Jan  2 14:39:19 2013 pluto[8551]: | handling event EVENT_PENDING_DDNS
>> Jan  2 14:39:19 2013 pluto[8551]: | event after this is
>> EVENT_PENDING_PHASE2 in 60 seconds
>> Jan  2 14:39:19 2013 pluto[8551]: | inserting event
>> EVENT_PENDING_DDNS, timeout in 60 seconds
>> Jan  2 14:39:19 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 60
>> seconds
>> Jan  2 14:39:27 2013 pluto[8551]: |
>> Jan  2 14:39:27 2013 pluto[8551]: | *received whack message
>> Jan  2 14:39:27 2013 pluto[8551]: | processing connection merkezvpn/0x2
>> Jan  2 14:39:27 2013 pluto[8551]: \"merkezvpn/0x2\": terminating SAs
>> using this connection
>> Jan  2 14:39:27 2013 pluto[8551]: | processing connection merkezvpn/0x2
>> Jan  2 14:39:27 2013 pluto[8551]: \"merkezvpn/0x2\" #3: deleting state
>> (STATE_QUICK_I2)
>> Jan  2 14:39:27 2013 pluto[8551]: | deleting state #3
>> Jan  2 14:39:27 2013 pluto[8551]: | sending 68 bytes for delete notify
>> through eth9.102:500 to RIGHT_EXT_IP:500 (using #4)
>> Jan  2 14:39:27 2013 pluto[8551]: | command executing down-client
>> Jan  2 14:39:27 2013 pluto[8551]: | executing down-client: 2>&1
>> PLUTO_VERB=\'down-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0x2\' PLUTO_INTERFACE=\'eth9.102\'
>> PLUTO_NEXT_HOP=\'10.46.1.5\' PLUTO_ME=\'LEFT_EXT_IP\'
>> PLUTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'10.46.0.0\' PLUTO_MY_CLIENT_MASK=\'255.255.0.0\'
>> PLUTO_MY_PORT=\'0\' PLUTO_MY_PROTOCOL=\'0\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'192.168.2.0/24\'
>> PLUTO_PEER_CLIENT_NET=\'192.168.2.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.255.0\' PLUTO_PEER_PORT=\'0\'
>> PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\' PLUTO_STACK=\'netkey\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+IKEv2ALLOW+SAREFTRACK\'
>> PLUTO_CONN_ADDRFAMILY=\'ipv4\' PLUTO_XAUTH_USERNAME=\'\'
>> PLUTO_MY_SOURCEIP=\'10.46.1.5\' PLUTO_IS_PEER_CISCO=\'0\'
>> PLUTO_CISCO_DNS_INFO=\'\' PLUTO_CISCO_DOMAIN_INFO=\'\'
>> PLUTO_PEER_BANNER=\'\' PLUTO_NM_CONFIGURED=\'0\' ipsec _updown
>> Jan  2 14:39:27 2013 pluto[8551]: | popen(): cmd is 852 chars long
>> Jan  2 14:39:27 2013 pluto[8551]: | cmd(   0):2>&1
>> PLUTO_VERB=\'down-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0x:
>> Jan  2 14:39:27 2013 pluto[8551]: | cmd(  80):2\'
>> PLUTO_INTERFACE=\'eth9.102\' PLUTO_NEXT_HOP=\'10.46.1.5\'
>> PLUTO_ME=\'LEFT_EXT_IP\' :
>> Jan  2 14:39:27 2013 pluto[8551]: | cmd(
>> 160):PLUTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'10:
>> Jan  2 14:39:27 2013 pluto[8551]: | cmd( 240):.46.0.0\'
>> PLUTO_MY_CLIENT_MASK=\'255.255.0.0\' PLUTO_MY_PORT=\'0\'
>> PLUTO_MY_PROTOCOL=:
>> Jan  2 14:39:27 2013 pluto[8551]: | cmd( 320):\'0\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'192.:
>> Jan  2 14:39:27 2013 pluto[8551]: | cmd( 400):168.2.0/24\'
>> PLUTO_PEER_CLIENT_NET=\'192.168.2.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.:
>> Jan  2 14:39:27 2013 pluto[8551]: | cmd( 480):255.0\'
>> PLUTO_PEER_PORT=\'0\' PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\'
>> PLUTO_STACK=:
>> Jan  2 14:39:27 2013 pluto[8551]: | cmd( 560):\'netkey\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+IKEv2ALLOW+SAREFTRACK\'
>> PLUT:
>> Jan  2 14:39:27 2013 pluto[8551]: | cmd(
>> 640):O_CONN_ADDRFAMILY=\'ipv4\' PLUTO_XAUTH_USERNAME=\'\'
>> PLUTO_MY_SOURCEIP=\'10.46.1.5\' P:
>> Jan  2 14:39:27 2013 pluto[8551]: | cmd( 720):LUTO_IS_PEER_CISCO=\'0\'
>> PLUTO_CISCO_DNS_INFO=\'\' PLUTO_CISCO_DOMAIN_INFO=\'\' PLUTO_:
>> Jan  2 14:39:27 2013 pluto[8551]: | cmd( 800):PEER_BANNER=\'\'
>> PLUTO_NM_CONFIGURED=\'0\' ipsec _updown:
>> Jan  2 14:39:27 2013 pluto[8551]: | request to replace with shunt a
>> prospective erouted policy with netkey kernel --- experimental
>> Jan  2 14:39:27 2013 pluto[8551]: | delete inbound eroute
>> 192.168.2.0/24:0 --0-> 10.46.0.0/16:0 => unk255.10000 at LEFT_EXT_IP
>> (raw_eroute)
>> Jan  2 14:39:27 2013 pluto[8551]: | raw_eroute result=1
>> Jan  2 14:39:27 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:39:27 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 52
>> seconds
>> Jan  2 14:39:27 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 52
>> seconds
>> Jan  2 14:39:28 2013 pluto[8551]: |
>> Jan  2 14:39:28 2013 pluto[8551]: | *received whack message
>> Jan  2 14:39:28 2013 pluto[8551]: | processing connection merkezvpn/0x2
>> Jan  2 14:39:28 2013 pluto[8551]: | kernel_alg_db_new() will return
>> p_new->protoid=3, p_new->trans_cnt=1
>> Jan  2 14:39:28 2013 pluto[8551]: | kernel_alg_db_new()     trans[0]:
>> transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=1
>> Jan  2 14:39:28 2013 pluto[8551]: | returning new proposal from esp_info
>> Jan  2 14:39:28 2013 pluto[8551]: | duplicating state object #4
>> Jan  2 14:39:28 2013 pluto[8551]: | creating state object #6 at 0xb7b27cf8
>> Jan  2 14:39:28 2013 pluto[8551]: | processing connection merkezvpn/0x2
>> Jan  2 14:39:28 2013 pluto[8551]: | ICOOKIE:  02 d4 a3 f4  91 a0 7e 97
>> Jan  2 14:39:28 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  a5 36 cb b0
>> Jan  2 14:39:28 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:39:28 2013 pluto[8551]: | inserting state object #6
>> Jan  2 14:39:28 2013 pluto[8551]: | inserting event EVENT_SO_DISCARD,
>> timeout in 0 seconds for #6
>> Jan  2 14:39:28 2013 pluto[8551]: \"merkezvpn/0x2\" #6: initiating
>> Quick Mode PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK {using
>> isakmp#4 msgid:f62dc883 proposal=3DES(3)_192-MD5(1)_096
>> pfsgroup=OAKLEY_GROUP_MODP1024}
>> Jan  2 14:39:28 2013 pluto[8551]: | helper -1 doing build_kenonce op id: 0
>> Jan  2 14:39:28 2013 pluto[8551]: | processing connection merkezvpn/0x2
>> Jan  2 14:39:28 2013 pluto[8551]: | kernel_alg_db_new() will return
>> p_new->protoid=3, p_new->trans_cnt=1
>> Jan  2 14:39:28 2013 pluto[8551]: | kernel_alg_db_new()     trans[0]:
>> transid=3, attr_cnt=1, attrs[0].type=5, attrs[0].val=1
>> Jan  2 14:39:28 2013 pluto[8551]: | returning new proposal from esp_info
>> Jan  2 14:39:28 2013 pluto[8551]: | sending 292 bytes for quick_outI1
>> through eth9.102:500 to RIGHT_EXT_IP:500 (using #6)
>> Jan  2 14:39:28 2013 pluto[8551]: | inserting event EVENT_RETRANSMIT,
>> timeout in 10 seconds for #6
>> Jan  2 14:39:28 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:39:28 2013 pluto[8551]: | next event EVENT_RETRANSMIT in 10
>> seconds for #6
>> Jan  2 14:39:28 2013 pluto[8551]: | next event EVENT_RETRANSMIT in 10
>> seconds for #6
>> Jan  2 14:39:28 2013 pluto[8551]: |
>> Jan  2 14:39:28 2013 pluto[8551]: | *received 324 bytes from
>> RIGHT_EXT_IP:500 on eth9.102 (port=500)
>> Jan  2 14:39:28 2013 pluto[8551]: |  processing version=1.0 packet
>> with exchange type=ISAKMP_XCHG_QUICK (32)
>> Jan  2 14:39:28 2013 pluto[8551]: | ICOOKIE:  02 d4 a3 f4  91 a0 7e 97
>> Jan  2 14:39:28 2013 pluto[8551]: | RCOOKIE:  fc 82 4a fb  a5 36 cb b0
>> Jan  2 14:39:28 2013 pluto[8551]: | state hash entry 8
>> Jan  2 14:39:28 2013 pluto[8551]: | v1 peer and cookies match on #6,
>> provided msgid 83c82df6 vs 83c82df6
>> Jan  2 14:39:28 2013 pluto[8551]: | v1 state object #6 found, in
>> STATE_QUICK_I1
>> Jan  2 14:39:28 2013 pluto[8551]: | processing connection merkezvpn/0x2
>> Jan  2 14:39:28 2013 pluto[8551]: \"merkezvpn/0x2\" #6: ignoring
>> informational payload, type IPSEC_RESPONDER_LIFETIME msgid=f62dc883
>> Jan  2 14:39:28 2013 pluto[8551]: | started looking for secret for
>> LEFT_EXT_IP->10.6.202.3 of kind PPK_PSK
>> Jan  2 14:39:28 2013 pluto[8551]: | actually looking for secret for
>> LEFT_EXT_IP->10.6.202.3 of kind PPK_PSK
>> Jan  2 14:39:28 2013 pluto[8551]: | 1: compared key 10.6.202.3 to
>> LEFT_EXT_IP / 10.6.202.3 -> 4
>> Jan  2 14:39:28 2013 pluto[8551]: | 2: compared key LEFT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 12
>> Jan  2 14:39:28 2013 pluto[8551]: | line 2: match=12
>> Jan  2 14:39:28 2013 pluto[8551]: | best_match 0>12 best=0xb7b0adc0
>> (line=2)
>> Jan  2 14:39:28 2013 pluto[8551]: | 1: compared key RIGHT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 0
>> Jan  2 14:39:28 2013 pluto[8551]: | 2: compared key LEFT_EXT_IP to
>> LEFT_EXT_IP / 10.6.202.3 -> 8
>> Jan  2 14:39:28 2013 pluto[8551]: | line 1: match=8
>> Jan  2 14:39:28 2013 pluto[8551]: | concluding with best_match=12
>> best=0xb7b0adc0 (lineno=2)
>> Jan  2 14:39:28 2013 pluto[8551]: | helper -1 doing compute dh(p2) op id:
>> 0
>> Jan  2 14:39:28 2013 pluto[8551]: | processing connection merkezvpn/0x2
>> Jan  2 14:39:28 2013 pluto[8551]: | our client is subnet 10.46.0.0/16
>> Jan  2 14:39:28 2013 pluto[8551]: | our client protocol/port is 0/0
>> Jan  2 14:39:28 2013 pluto[8551]: | peer client is subnet 192.168.2.0/24
>> Jan  2 14:39:28 2013 pluto[8551]: | peer client protocol/port is 0/0
>> Jan  2 14:39:28 2013 pluto[8551]: | install_ipsec_sa() for #6: inbound
>> and outbound
>> Jan  2 14:39:28 2013 pluto[8551]: | route owner of \"merkezvpn/0x2\"
>> prospective erouted: self; eroute owner: self
>> Jan  2 14:39:28 2013 pluto[8551]: | could_route called for
>> merkezvpn/0x2 (kind=CK_PERMANENT)
>> Jan  2 14:39:28 2013 pluto[8551]: | add inbound eroute
>> 192.168.2.0/24:0 --0-> 10.46.0.0/16:0 => tun.10000 at LEFT_EXT_IP
>> (raw_eroute)
>> Jan  2 14:39:28 2013 pluto[8551]: | raw_eroute result=1
>> Jan  2 14:39:28 2013 pluto[8551]: | sr for #6: prospective erouted
>> Jan  2 14:39:28 2013 pluto[8551]: | route owner of \"merkezvpn/0x2\"
>> prospective erouted: self; eroute owner: self
>> Jan  2 14:39:28 2013 pluto[8551]: | eroute_connection replace eroute
>> 10.46.0.0/16:0 --0-> 192.168.2.0/24:0 => tun.0 at RIGHT_EXT_IP
>> (raw_eroute)
>> Jan  2 14:39:28 2013 pluto[8551]: | raw_eroute result=1
>> Jan  2 14:39:28 2013 pluto[8551]: | command executing up-client
>> Jan  2 14:39:28 2013 pluto[8551]: | executing up-client: 2>&1
>> PLUTO_VERB=\'up-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0x2\' PLUTO_INTERFACE=\'eth9.102\'
>> PLUTO_NEXT_HOP=\'10.46.1.5\' PLUTO_ME=\'LEFT_EXT_IP\'
>> PLUTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'10.46.0.0\' PLUTO_MY_CLIENT_MASK=\'255.255.0.0\'
>> PLUTO_MY_PORT=\'0\' PLUTO_MY_PROTOCOL=\'0\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'192.168.2.0/24\'
>> PLUTO_PEER_CLIENT_NET=\'192.168.2.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.255.0\' PLUTO_PEER_PORT=\'0\'
>> PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\' PLUTO_STACK=\'netkey\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK\'
>> PLUTO_CONN_ADDRFAMILY=\'ipv4\' PLUTO_XAUTH_USERNAME=\'\'
>> PLUTO_MY_SOURCEIP=\'10.46.1.5\' PLUTO_IS_PEER_CISCO=\'0\'
>> PLUTO_CISCO_DNS_INFO=\'\' PLUTO_CISCO_DOMAIN_INFO=\'\'
>> PLUTO_PEER_BANNER=\'\' PLUTO_NM_CONFIGURED=\'0\' ipsec _updown
>> Jan  2 14:39:28 2013 pluto[8551]: | popen(): cmd is 853 chars long
>> Jan  2 14:39:28 2013 pluto[8551]: | cmd(   0):2>&1
>> PLUTO_VERB=\'up-client\' PLUTO_VERSION=\'2.0\'
>> PLUTO_CONNECTION=\'merkezvpn/0x2\':
>> Jan  2 14:39:28 2013 pluto[8551]: | cmd(  80):
>> PLUTO_INTERFACE=\'eth9.102\' PLUTO_NEXT_HOP=\'10.46.1.5\'
>> PLUTO_ME=\'LEFT_EXT_IP\' PL:
>> Jan  2 14:39:28 2013 pluto[8551]: | cmd(
>> 160):UTO_MY_ID=\'LEFT_EXT_IP\' PLUTO_MY_CLIENT=\'10.46.0.0/16\'
>> PLUTO_MY_CLIENT_NET=\'10.4:
>> Jan  2 14:39:28 2013 pluto[8551]: | cmd( 240):6.0.0\'
>> PLUTO_MY_CLIENT_MASK=\'255.255.0.0\' PLUTO_MY_PORT=\'0\'
>> PLUTO_MY_PROTOCOL=\'0:
>> Jan  2 14:39:28 2013 pluto[8551]: | cmd( 320):\'
>> PLUTO_PEER=\'RIGHT_EXT_IP\' PLUTO_PEER_ID=\'10.6.202.3\'
>> PLUTO_PEER_CLIENT=\'192.16:
>> Jan  2 14:39:28 2013 pluto[8551]: | cmd( 400):8.2.0/24\'
>> PLUTO_PEER_CLIENT_NET=\'192.168.2.0\'
>> PLUTO_PEER_CLIENT_MASK=\'255.255.25:
>> Jan  2 14:39:28 2013 pluto[8551]: | cmd( 480):5.0\'
>> PLUTO_PEER_PORT=\'0\' PLUTO_PEER_PROTOCOL=\'0\' PLUTO_PEER_CA=\'\'
>> PLUTO_STACK=\'n:
>> Jan  2 14:39:28 2013 pluto[8551]: | cmd( 560):etkey\'
>> PLUTO_CONN_POLICY=\'PSK+ENCRYPT+TUNNEL+PFS+UP+IKEv2ALLOW+SAREFTRACK\'
>> PLU:
>> Jan  2 14:39:28 2013 pluto[8551]: | cmd(
>> 640):TO_CONN_ADDRFAMILY=\'ipv4\' PLUTO_XAUTH_USERNAME=\'\'
>> PLUTO_MY_SOURCEIP=\'10.46.1.5\' :
>> Jan  2 14:39:28 2013 pluto[8551]: | cmd(
>> 720):PLUTO_IS_PEER_CISCO=\'0\' PLUTO_CISCO_DNS_INFO=\'\'
>> PLUTO_CISCO_DOMAIN_INFO=\'\' PLUTO:
>> Jan  2 14:39:28 2013 pluto[8551]: | cmd( 800):_PEER_BANNER=\'\'
>> PLUTO_NM_CONFIGURED=\'0\' ipsec _updown:
>> Jan  2 14:39:28 2013 pluto[8551]: | route_and_eroute: firewall_notified:
>> true
>> Jan  2 14:39:28 2013 pluto[8551]: | route_and_eroute: instance
>> \"merkezvpn/0x2\", setting eroute_owner {spd=0xb7b107a8,sr=0xb7b107a8}
>> to #6 (was #0) (newest_ipsec_sa=#0)
>> Jan  2 14:39:28 2013 pluto[8551]: | complete state transition with STF_OK
>> Jan  2 14:39:28 2013 pluto[8551]: \"merkezvpn/0x2\" #6: transition
>> from state STATE_QUICK_I1 to state STATE_QUICK_I2
>> Jan  2 14:39:28 2013 pluto[8551]: | sending reply packet to
>> RIGHT_EXT_IP:500 (from port 500)
>> Jan  2 14:39:28 2013 pluto[8551]: | sending 52 bytes for
>> STATE_QUICK_I1 through eth9.102:500 to RIGHT_EXT_IP:500 (using #6)
>> Jan  2 14:39:28 2013 pluto[8551]: | inserting event EVENT_SA_REPLACE,
>> timeout in 85754 seconds for #6
>> Jan  2 14:39:28 2013 pluto[8551]: \"merkezvpn/0x2\" #6:
>> STATE_QUICK_I2: sent QI2, IPsec SA established tunnel mode
>> {ESP=>0xc688ca25 <0x257c26f7 xfrm=3DES_0-HMAC_MD5 NATOA=none NATD=none
>> DPD=none}
>>
>>
>>
>>
>> Jan  2 14:39:28 2013 pluto[8551]: | modecfg pull: noquirk policy:push
>> not-client
>> Jan  2 14:39:28 2013 pluto[8551]: | phase 1 is done, looking for phase
>> 2 to unpend
>> Jan  2 14:39:28 2013 pluto[8551]: | complete state transition with
>> STF_INLINE
>> Jan  2 14:39:28 2013 pluto[8551]: | * processed 0 messages from
>> cryptographic helpers
>> Jan  2 14:39:28 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 51
>> seconds
>> Jan  2 14:39:28 2013 pluto[8551]: | next event EVENT_PENDING_DDNS in 51
>> seconds
>>
>>
>>
>> --
>> Oguz YILMAZ
>>
>>
>> On Wed, Jan 2, 2013 at 2:09 PM, Philippe Vouters
>> <philippe.vouters at laposte.net> wrote:
>>>
>>> Dear Oguz,
>>>
>>> Can you set plutodebug to only "control" ? I observed that the more you
>>> attempt to log with Libreswan, the more you loose log entries.
>>> I am interested in observing why the so frequent STATE_QUICK_I2.
>>> By the way, is there any reason why you commented out:
>>>
>>> #        dpdaction=restart
>>> #        dpddelay=30
>>> #        dpdtimeout=120
>>>
>>> ???
>>>
>>> Philippe Vouters (Fontainebleau/France)
>>> URL: http://vouters.dyndns.org/
>>> SIP: sip:Vouters at sip.linphone.org
>>>
>>> Le 02/01/2013 11:36, Oguz Yilmaz a écrit :
>>>>
>>>> Log is below the email. O have seperated parts for easy perception.
>>>>
>>>> --
>>>> Oguz YILMAZ
>>>>
>>>>
>>>> On Wed, Jan 2, 2013 at 12:20 PM, Philippe Vouters
>>>> <philippe.vouters at laposte.net> wrote:
>>>>>
>>>>> Can you send us a relevant extract of your log file ?
>>>>>
>>>>> Philippe Vouters (Fontainebleau/France)
>>>>> URL: http://vouters.dyndns.org/
>>>>> SIP: sip:Vouters at sip.linphone.org
>>>>>
>>>>> Le 02/01/2013 11:09, Oguz Yilmaz a écrit :
>>>>>>
>>>>>> Hello,
>>>>>>
>>>>>> I have successfully established vpn connection. However there is
>>>>>> continuous reestablishment of the connection. I have 2 questions:
>>>>>>
>>>>>>
>>>>>>
>>>>>> 11:49:23: restart of ipsec
>>>>>>
>>>>>> 11:51:09: Connection STATE_QUICK_I2
>>>>>>
>>>>>> 1- Why it takes about 2 minutes after restart of ipsec to establish
>>>>>> connection?
>>>>>>
>>>>>> 11:51:28: Connection STATE_QUICK_I2
>>>>>>
>>>>>> 11:54:28: Connection STATE_QUICK_I2
>>>>>>
>>>>>> 2- Why it reestablish connection after about 3 minutes repetitively?
>>>>>>
>>>>>>
>>>>>> Only interference I do after starting ipsec is; Each minute I run
>>>>>> "ipsec auto --status" for specific logging purpose.
>>>>>>
>>>>>>
>>>>>> version 2.0
>>>>>>
>>>>>> config setup
>>>>>>            interfaces=%defaultroute
>>>>>>            klipsdebug=none
>>>>>>            plutodebug="control lifecycle dpd"
>>>>>>            nat_traversal=no
>>>>>>
>>>>>>
>>>>>>
>>>>>> virtual_private=%v4:10.0.0.0/8,%v4:172.16.0.0/12,%v4:192.168.0.0/16,%v4:!172.19.32.0/24
>>>>>>            protostack=netkey
>>>>>>
>>>>>>
>>>>>> conn %default
>>>>>>            auto=add
>>>>>>
>>>>>> conn myvpn
>>>>>>            authby=secret
>>>>>>            auth=esp
>>>>>>            esp=3des-md5-96
>>>>>>            leftsourceip=10.46.1.5
>>>>>>            left=LEFT_EXT_IP
>>>>>>            leftsubnet=10.46.0.0/16
>>>>>>            right=RIGHT_EXT_IP
>>>>>>            rightid=10.6.202.3
>>>>>>            rightsubnets={10.6.0.0/16,192.168.2.0/24}
>>>>>>            leftnexthop=LEFT_EXT_GW
>>>>>>            disablearrivalcheck=no
>>>>>>            auto=start
>>>>>>            keylife=86400s
>>>>>>            pfs=yes
>>>>>>            keyexchange=ike
>>>>>>            ikelifetime=86400s
>>>>>>            ike=3des-md5-modp1024
>>>>>> #        dpdaction=restart
>>>>>> #        dpddelay=30
>>>>>> #        dpdtimeout=120
>>>>>>
>>>>>>
>>>>>> conn passthru
>>>>>>            type=passthrough
>>>>>>            leftsubnet=10.46.0.0/16
>>>>>>            rightsubnet=10.46.0.0/16
>>>>>>            left=10.46.1.5
>>>>>>            right=0.0.0.0
>>>>>>            authby=never
>>>>>>            auto=route
>>>>>>
>>>>>>
>>>>>>
>


More information about the Swan mailing list