13/09/26 15:07:52 ## : IKE Daemon, ver 2.2.1
13/09/26 15:07:52 ## : Copyright 2013 Shrew Soft Inc.
13/09/26 15:07:52 ## : This product linked OpenSSL 1.0.1e-fips 11 Feb 2013
13/09/26 15:07:52 ii : opened '/var/log/iked.log'
13/09/26 15:07:52 ii : ipc server process thread begin ...
13/09/26 15:07:52 ii : pfkey process thread begin ...
13/09/26 15:07:52 ii : network process thread begin ...
13/09/26 15:07:52 K< : recv pfkey REGISTER AH message
13/09/26 15:07:52 K< : recv pfkey REGISTER ESP message
13/09/26 15:07:52 K< : recv pfkey REGISTER IPCOMP message
13/09/26 15:07:52 K! : recv X_SPDDUMP message failure ( errno = 2 )
13/09/26 15:07:55 ii : ipc client process thread begin ...
13/09/26 15:07:55 <A : peer config add message
13/09/26 15:07:55 <A : proposal config message
13/09/26 15:07:55 <A : proposal config message
13/09/26 15:07:55 <A : client config message
13/09/26 15:07:55 <A : xauth username message
13/09/26 15:07:55 <A : xauth password message
13/09/26 15:07:55 <A : remote certificate data message
13/09/26 15:07:55 ii : remote certificate read complete ( 889 bytes )
13/09/26 15:07:55 <A : local certificate data message
13/09/26 15:07:55 ii : local certificate read complete ( 1493 bytes )
13/09/26 15:07:55 <A : local key data message
13/09/26 15:07:55 ii : local key read complete ( 1193 bytes )
13/09/26 15:07:55 <A : peer tunnel enable message
13/09/26 15:07:55 DB : peer added ( obj count = 1 )
13/09/26 15:07:55 ii : local address S.S.S.S selected for peer
13/09/26 15:07:55 DB : tunnel added ( obj count = 1 )
13/09/26 15:07:55 ii : obtained x509 cert subject ( 159 bytes )
13/09/26 15:07:55 DB : new phase1 ( ISAKMP initiator )
13/09/26 15:07:55 DB : exchange type is identity protect
13/09/26 15:07:55 DB : C.C.C.C:500 <-> S.S.S.S:500
13/09/26 15:07:55 DB : 3700000049000000:0000000000000000
13/09/26 15:07:55 DB : phase1 added ( obj count = 1 )
13/09/26 15:07:55 >> : security association payload
13/09/26 15:07:55 >> : - proposal #1 payload 
13/09/26 15:07:55 >> : -- transform #1 payload 
13/09/26 15:07:55 >> : vendor id payload
13/09/26 15:07:55 ii : local supports XAUTH
13/09/26 15:07:55 >> : vendor id payload
13/09/26 15:07:55 ii : local supports nat-t ( draft v00 )
13/09/26 15:07:55 >> : vendor id payload
13/09/26 15:07:55 ii : local supports nat-t ( draft v01 )
13/09/26 15:07:55 >> : vendor id payload
13/09/26 15:07:55 ii : local supports nat-t ( draft v02 )
13/09/26 15:07:55 >> : vendor id payload
13/09/26 15:07:55 ii : local supports nat-t ( draft v03 )
13/09/26 15:07:55 >> : vendor id payload
13/09/26 15:07:55 ii : local supports nat-t ( rfc )
13/09/26 15:07:55 >> : vendor id payload
13/09/26 15:07:55 ii : local supports FRAGMENTATION
13/09/26 15:07:55 >> : vendor id payload
13/09/26 15:07:55 >> : vendor id payload
13/09/26 15:07:55 ii : local supports DPDv1
13/09/26 15:07:55 >> : vendor id payload
13/09/26 15:07:55 ii : local is SHREW SOFT compatible
13/09/26 15:07:55 >> : vendor id payload
13/09/26 15:07:55 ii : local is NETSCREEN compatible
13/09/26 15:07:55 >> : vendor id payload
13/09/26 15:07:55 ii : local is SIDEWINDER compatible
13/09/26 15:07:55 >> : vendor id payload
13/09/26 15:07:55 ii : local is CISCO UNITY compatible
13/09/26 15:07:55 >= : cookies 3700000049000000:0000000000000000
13/09/26 15:07:55 >= : message 00000000
13/09/26 15:07:55 -> : send IKE packet C.C.C.C:500 -> S.S.S.S:500 ( 372 bytes )
13/09/26 15:07:55 DB : phase1 resend event scheduled ( ref count = 2 )
13/09/26 15:07:56 <- : recv IKE packet S.S.S.S:500 -> C.C.C.C:500 ( 136 bytes )
13/09/26 15:07:56 DB : phase1 found
13/09/26 15:07:56 ii : processing phase1 packet ( 136 bytes )
13/09/26 15:07:56 =< : cookies 3700000049000000:a800000085000000
13/09/26 15:07:56 =< : message 00000000
13/09/26 15:07:56 << : security association payload
13/09/26 15:07:56 << : - propsal #1 payload 
13/09/26 15:07:56 << : -- transform #1 payload 
13/09/26 15:07:56 ii : matched isakmp proposal #1 transform #1
13/09/26 15:07:56 ii : - transform    = ike
13/09/26 15:07:56 ii : - cipher type  = 3des
13/09/26 15:07:56 ii : - key length   = default
13/09/26 15:07:56 ii : - hash type    = sha1
13/09/26 15:07:56 ii : - dh group     = group2 ( modp-1024 )
13/09/26 15:07:56 ii : - auth type    = xauth-initiator-rsa
13/09/26 15:07:56 ii : - life seconds = 86400
13/09/26 15:07:56 ii : - life kbytes  = 0
13/09/26 15:07:56 << : vendor id payload
13/09/26 15:07:56 ii : peer supports XAUTH
13/09/26 15:07:56 << : vendor id payload
13/09/26 15:07:56 ii : peer supports DPDv1
13/09/26 15:07:56 << : vendor id payload
13/09/26 15:07:56 ii : peer supports nat-t ( rfc )
13/09/26 15:07:56 >> : key exchange payload
13/09/26 15:07:56 >> : nonce payload
13/09/26 15:07:56 >> : cert request payload
13/09/26 15:07:56 >> : nat discovery payload
13/09/26 15:07:56 >> : nat discovery payload
13/09/26 15:07:56 >= : cookies 3700000049000000:a800000085000000
13/09/26 15:07:56 >= : message 00000000
13/09/26 15:07:56 DB : phase1 resend event canceled ( ref count = 1 )
13/09/26 15:07:56 -> : send IKE packet C.C.C.C:500 -> S.S.S.S:500 ( 265 bytes )
13/09/26 15:07:56 DB : phase1 resend event scheduled ( ref count = 2 )
13/09/26 15:07:56 <- : recv IKE packet S.S.S.S:500 -> C.C.C.C:500 ( 328 bytes )
13/09/26 15:07:56 DB : phase1 found
13/09/26 15:07:56 ii : processing phase1 packet ( 328 bytes )
13/09/26 15:07:56 =< : cookies 3700000049000000:a800000085000000
13/09/26 15:07:56 =< : message 00000000
13/09/26 15:07:56 << : key exchange payload
13/09/26 15:07:56 << : nonce payload
13/09/26 15:07:56 << : cert request payload
13/09/26 15:07:56 << : nat discovery payload
13/09/26 15:07:56 << : nat discovery payload
13/09/26 15:07:56 ii : nat discovery - local address is translated
13/09/26 15:07:56 ii : switching to src nat-t udp port 4500
13/09/26 15:07:56 ii : switching to dst nat-t udp port 4500
13/09/26 15:07:56 == : DH shared secret ( 128 bytes )
13/09/26 15:07:56 == : SETKEYID ( 20 bytes )
13/09/26 15:07:56 == : SETKEYID_d ( 20 bytes )
13/09/26 15:07:56 == : SETKEYID_a ( 20 bytes )
13/09/26 15:07:56 == : SETKEYID_e ( 20 bytes )
13/09/26 15:07:56 == : cipher key ( 40 bytes )
13/09/26 15:07:56 == : cipher iv ( 8 bytes )
13/09/26 15:07:56 >> : identification payload
13/09/26 15:07:56 >> : certificate payload
13/09/26 15:07:56 == : phase1 hash_i ( computed ) ( 20 bytes )
13/09/26 15:07:56 >> : signature payload
13/09/26 15:07:56 >= : cookies 3700000049000000:a800000085000000
13/09/26 15:07:56 >= : message 00000000
13/09/26 15:07:56 >= : encrypt iv ( 8 bytes )
13/09/26 15:07:56 == : encrypt packet ( 1953 bytes )
13/09/26 15:07:56 == : stored iv ( 8 bytes )
13/09/26 15:07:56 DB : phase1 resend event canceled ( ref count = 1 )
13/09/26 15:07:56 -> : send NAT-T:IKE packet C.C.C.C:4500 -> S.S.S.S:4500 ( 1988 bytes )
13/09/26 15:07:56 <- : recv NAT-T:IKE packet S.S.S.S:4500 -> C.C.C.C:4500 ( 76 bytes )
13/09/26 15:07:56 DB : phase1 found
13/09/26 15:07:56 ii : processing config packet ( 76 bytes )
13/09/26 15:07:56 DB : config not found
13/09/26 15:07:56 DB : config added ( obj count = 1 )
13/09/26 15:07:56 == : new config iv ( 8 bytes )
13/09/26 15:07:56 !! : config packet ignored ( phase1 not mature )
13/09/26 15:07:56 <- : recv NAT-T:IKE packet S.S.S.S:4500 -> C.C.C.C:4500 ( 1908 bytes )
13/09/26 15:07:56 DB : phase1 found
13/09/26 15:07:56 ii : processing phase1 packet ( 1908 bytes )
13/09/26 15:07:56 =< : cookies 3700000049000000:a800000085000000
13/09/26 15:07:56 =< : message 00000000
13/09/26 15:07:56 =< : decrypt iv ( 8 bytes )
13/09/26 15:07:56 == : decrypt packet ( 1908 bytes )
13/09/26 15:07:56 <= : trimmed packet padding ( 3 bytes )
13/09/26 15:07:56 <= : stored iv ( 8 bytes )
13/09/26 15:07:56 << : identification payload
13/09/26 15:07:56 ii : phase1 id match ( cert check only )
13/09/26 15:07:56 ii : received = asn1-dn C=SK,ST=XXX,L=XXXXXXX,O=XXXXXXX,OU=XXXXXXXX,CN=XXXXXXXX
13/09/26 15:07:56 << : certificate payload
13/09/26 15:07:56 << : signature payload
13/09/26 15:07:56 ii : unable to get certificate CRL(3) at depth:0
13/09/26 15:07:56 ii : subject /C=SK/ST=XXX/L=XXXXXXX/O=XXXXXXXX/OU=XXXXXXXXX/CN=XXXXXXXXX
13/09/26 15:07:56 ii : unable to get certificate CRL(3) at depth:1
13/09/26 15:07:56 ii : subject /DC=sk/DC=XXXXXX/CN=XXXXXXXXXX
13/09/26 15:07:56 == : phase1 hash_r ( computed ) ( 20 bytes )
13/09/26 15:07:56 == : phase1 hash_r ( received ) ( 20 bytes )
13/09/26 15:07:56 ii : phase1 sa established
13/09/26 15:07:56 ii : S.S.S.S:4500 <-> C.C.C.C:4500
13/09/26 15:07:56 ii : 3700000049000000:a800000085000000
13/09/26 15:07:56 ii : sending peer INITIAL-CONTACT notification
13/09/26 15:07:56 ii : - C.C.C.C:4500 -> S.S.S.S:4500
13/09/26 15:07:56 ii : - isakmp spi = 3700000049000000:a800000085000000
13/09/26 15:07:56 ii : - data size 0
13/09/26 15:07:56 >> : hash payload
13/09/26 15:07:56 >> : notification payload
13/09/26 15:07:56 == : new informational hash ( 20 bytes )
13/09/26 15:07:56 == : new informational iv ( 8 bytes )
13/09/26 15:07:56 >= : cookies 3700000049000000:a800000085000000
13/09/26 15:07:56 >= : message 0a1f3f7c
13/09/26 15:07:56 >= : encrypt iv ( 8 bytes )
13/09/26 15:07:56 == : encrypt packet ( 80 bytes )
13/09/26 15:07:56 == : stored iv ( 8 bytes )
13/09/26 15:07:56 -> : send NAT-T:IKE packet C.C.C.C:4500 -> S.S.S.S:4500 ( 116 bytes )
13/09/26 15:07:56 DB : phase2 not found
13/09/26 15:08:00 <- : recv NAT-T:IKE packet S.S.S.S:4500 -> C.C.C.C:4500 ( 76 bytes )
13/09/26 15:08:00 DB : phase1 found
13/09/26 15:08:00 ii : processing config packet ( 76 bytes )
13/09/26 15:08:00 DB : config found
13/09/26 15:08:00 =< : cookies 3700000049000000:a800000085000000
13/09/26 15:08:00 =< : message 57cc32fc
13/09/26 15:08:00 =< : decrypt iv ( 8 bytes )
13/09/26 15:08:00 == : decrypt packet ( 76 bytes )
13/09/26 15:08:00 !! : validate packet failed ( reserved value is non-null )
13/09/26 15:08:00 !! : config packet ignored ( packet decryption error )
13/09/26 15:08:07 <- : recv NAT-T:IKE packet S.S.S.S:4500 -> C.C.C.C:4500 ( 76 bytes )
13/09/26 15:08:07 DB : phase1 found
13/09/26 15:08:07 ii : processing config packet ( 76 bytes )
13/09/26 15:08:07 DB : config found
13/09/26 15:08:07 =< : cookies 3700000049000000:a800000085000000
13/09/26 15:08:07 =< : message 57cc32fc
13/09/26 15:08:07 =< : decrypt iv ( 8 bytes )
13/09/26 15:08:07 == : decrypt packet ( 76 bytes )
13/09/26 15:08:07 !! : validate packet failed ( reserved value is non-null )
13/09/26 15:08:07 !! : config packet ignored ( packet decryption error )
13/09/26 15:08:11 DB : phase1 found
13/09/26 15:08:11 ii : sending peer DPDV1-R-U-THERE notification
13/09/26 15:08:11 ii : - C.C.C.C:4500 -> S.S.S.S:4500
13/09/26 15:08:11 ii : - isakmp spi = 3700000049000000:a800000085000000
13/09/26 15:08:11 ii : - data size 4
13/09/26 15:08:11 >> : hash payload
13/09/26 15:08:11 >> : notification payload
13/09/26 15:08:11 == : new informational hash ( 20 bytes )
13/09/26 15:08:11 == : new informational iv ( 8 bytes )
13/09/26 15:08:11 >= : cookies 3700000049000000:a800000085000000
13/09/26 15:08:11 >= : message af726eb5
13/09/26 15:08:11 >= : encrypt iv ( 8 bytes )
13/09/26 15:08:11 == : encrypt packet ( 84 bytes )
13/09/26 15:08:11 == : stored iv ( 8 bytes )
13/09/26 15:08:11 -> : send NAT-T:IKE packet C.C.C.C:4500 -> S.S.S.S:4500 ( 116 bytes )
13/09/26 15:08:11 ii : DPD ARE-YOU-THERE sequence 34747ac8 requested
13/09/26 15:08:11 DB : phase1 found
13/09/26 15:08:11 -> : send NAT-T:KEEP-ALIVE packet C.C.C.C:4500 -> S.S.S.S:4500
13/09/26 15:08:20 <- : recv NAT-T:IKE packet S.S.S.S:4500 -> C.C.C.C:4500 ( 76 bytes )
13/09/26 15:08:20 DB : phase1 found
13/09/26 15:08:20 ii : processing config packet ( 76 bytes )
13/09/26 15:08:20 DB : config found
13/09/26 15:08:20 =< : cookies 3700000049000000:a800000085000000
13/09/26 15:08:20 =< : message 57cc32fc
13/09/26 15:08:20 =< : decrypt iv ( 8 bytes )
13/09/26 15:08:20 == : decrypt packet ( 76 bytes )
13/09/26 15:08:20 !! : validate packet failed ( reserved value is non-null )
13/09/26 15:08:20 !! : config packet ignored ( packet decryption error )
13/09/26 15:08:26 DB : phase1 found
13/09/26 15:08:26 -> : send NAT-T:KEEP-ALIVE packet C.C.C.C:4500 -> S.S.S.S:4500
13/09/26 15:08:26 DB : phase1 found
13/09/26 15:08:26 ii : next tunnel DPD retry in 4 secs for peer S.S.S.S:4500
13/09/26 15:08:26 ii : sending peer DPDV1-R-U-THERE notification
13/09/26 15:08:26 ii : - C.C.C.C:4500 -> S.S.S.S:4500
13/09/26 15:08:26 ii : - isakmp spi = 3700000049000000:a800000085000000
13/09/26 15:08:26 ii : - data size 4
13/09/26 15:08:26 >> : hash payload
13/09/26 15:08:26 >> : notification payload
13/09/26 15:08:26 == : new informational hash ( 20 bytes )
13/09/26 15:08:26 == : new informational iv ( 8 bytes )
13/09/26 15:08:26 >= : cookies 3700000049000000:a800000085000000
13/09/26 15:08:26 >= : message 931eb370
13/09/26 15:08:26 >= : encrypt iv ( 8 bytes )
13/09/26 15:08:26 == : encrypt packet ( 84 bytes )
13/09/26 15:08:26 == : stored iv ( 8 bytes )
13/09/26 15:08:26 -> : send NAT-T:IKE packet C.C.C.C:4500 -> S.S.S.S:4500 ( 116 bytes )
13/09/26 15:08:26 ii : DPD ARE-YOU-THERE sequence 34747ac9 requested
13/09/26 15:08:30 DB : phase1 found
13/09/26 15:08:30 ii : next tunnel DPD retry in 3 secs for peer S.S.S.S:4500
13/09/26 15:08:30 ii : sending peer DPDV1-R-U-THERE notification
13/09/26 15:08:30 ii : - C.C.C.C:4500 -> S.S.S.S:4500
13/09/26 15:08:30 ii : - isakmp spi = 3700000049000000:a800000085000000
13/09/26 15:08:30 ii : - data size 4
13/09/26 15:08:30 >> : hash payload
13/09/26 15:08:30 >> : notification payload
13/09/26 15:08:30 == : new informational hash ( 20 bytes )
13/09/26 15:08:30 == : new informational iv ( 8 bytes )
13/09/26 15:08:30 >= : cookies 3700000049000000:a800000085000000
13/09/26 15:08:30 >= : message 81832fa5
13/09/26 15:08:30 >= : encrypt iv ( 8 bytes )
13/09/26 15:08:30 == : encrypt packet ( 84 bytes )
13/09/26 15:08:30 == : stored iv ( 8 bytes )
13/09/26 15:08:30 -> : send NAT-T:IKE packet C.C.C.C:4500 -> S.S.S.S:4500 ( 116 bytes )
13/09/26 15:08:30 ii : DPD ARE-YOU-THERE sequence 34747aca requested
13/09/26 15:08:33 ii : hard halt signal received, shutting down
13/09/26 15:08:33 DB : removing all peer tunnel references
13/09/26 15:08:33 DB : tunnel dpd event canceled ( ref count = 5 )
13/09/26 15:08:33 DB : tunnel natt event canceled ( ref count = 4 )
13/09/26 15:08:33 DB : removing tunnel config references
13/09/26 15:08:33 DB : config deleted ( obj count = 0 )
13/09/26 15:08:33 DB : removing tunnel phase2 references
13/09/26 15:08:33 DB : removing tunnel phase1 references
13/09/26 15:08:33 DB : phase1 soft event canceled ( ref count = 3 )
13/09/26 15:08:33 DB : phase1 hard event canceled ( ref count = 2 )
13/09/26 15:08:33 DB : phase1 dead event canceled ( ref count = 1 )
13/09/26 15:08:33 ii : sending peer DELETE message
13/09/26 15:08:33 ii : - C.C.C.C:4500 -> S.S.S.S:4500
13/09/26 15:08:33 ii : - isakmp spi = 3700000049000000:a800000085000000
13/09/26 15:08:33 ii : - data size 0
13/09/26 15:08:33 >> : hash payload
13/09/26 15:08:33 >> : delete payload
13/09/26 15:08:33 == : new informational hash ( 20 bytes )
13/09/26 15:08:33 == : new informational iv ( 8 bytes )
13/09/26 15:08:33 >= : cookies 3700000049000000:a800000085000000
13/09/26 15:08:33 >= : message 69c2d1db
13/09/26 15:08:33 >= : encrypt iv ( 8 bytes )
13/09/26 15:08:33 == : encrypt packet ( 80 bytes )
13/09/26 15:08:33 == : stored iv ( 8 bytes )
13/09/26 15:08:33 -> : send NAT-T:IKE packet C.C.C.C:4500 -> S.S.S.S:4500 ( 116 bytes )
13/09/26 15:08:33 ii : phase1 removal before expire time
13/09/26 15:08:33 DB : phase1 deleted ( obj count = 0 )
13/09/26 15:08:33 DB : policy not found
13/09/26 15:08:33 DB : policy not found
13/09/26 15:08:33 DB : tunnel deleted ( obj count = 0 )
13/09/26 15:08:33 DB : peer deleted ( obj count = 0 )
13/09/26 15:08:33 ii : ipc client process thread exit ...
13/09/26 15:08:33 ii : ipc server process thread exit ...
13/09/26 15:08:33 ii : pfkey process thread exit ...
13/09/26 15:08:33 ii : network process thread exit ...
