[vpn-help] shrew -> NAT(linux)-> strongswan = disconnected

sftf sftf-misc at mail.ru
Wed Jun 23 02:10:11 CDT 2010


I have successfully configured Shrew VPN Client 2.1.5 to work with strongswan.
Without NAT between client and server everything ok.
But when client connecting to the gateway through NAT (linux box or DLink DIR-300)
connection is established ("tunnel enabled"), but after a while becomes disconnected ("gateway is not responding").
client(192.168.0.25)<-->(192.168.0.254)NAT_box(195.162.66.179)<-->gateway(195.162.66.178)
NAT_box allow all tarffic. On gateway esp,ah,udp 500, 4500 are opened for inbound and outbound connections.

What to look for?
Logs below.

=========
10/06/23 09:38:33 ## : IKE Daemon, ver 2.1.5
10/06/23 09:38:33 ## : Copyright 2009 Shrew Soft Inc.
10/06/23 09:38:33 ## : This product linked OpenSSL 0.9.8h 28 May 2008
10/06/23 09:38:33 ii : opened 'C:\Program Files\ShrewSoft\VPN Client\debug\iked.log'
10/06/23 09:38:33 ii : rebuilding vnet device list ...
10/06/23 09:38:33 ii : device ROOT\VNET\0000 disabled
10/06/23 09:38:33 ii : network process thread begin ...
10/06/23 09:38:33 ii : pfkey process thread begin ...
10/06/23 09:38:33 ii : ipc server process thread begin ...
10/06/23 09:38:33 K< : recv pfkey X_SPDDUMP UNSPEC message
10/06/23 09:38:33 DB : policy added ( obj count = 1 )
10/06/23 09:38:33 K< : recv pfkey X_SPDDUMP UNSPEC message
10/06/23 09:38:33 DB : policy added ( obj count = 2 )
10/06/23 09:38:33 K< : recv pfkey X_SPDDUMP UNSPEC message
10/06/23 09:38:33 DB : policy added ( obj count = 3 )
10/06/23 09:38:36 ii : ipc client process thread begin ...
10/06/23 09:38:36 <A : peer config add message
10/06/23 09:38:36 DB : peer added ( obj count = 1 )
10/06/23 09:38:36 ii : local address 192.168.0.25 selected for peer
10/06/23 09:38:36 DB : tunnel added ( obj count = 1 )
10/06/23 09:38:36 <A : proposal config message
10/06/23 09:38:36 <A : proposal config message
10/06/23 09:38:36 <A : client config message
10/06/23 09:38:36 <A : xauth username message
10/06/23 09:38:36 <A : xauth password message
10/06/23 09:38:36 <A : remote cert 'C:\Documents and Settings\organ\Мои документы\Shrew Soft VPN\certs\organca-cert.pem' message
10/06/23 09:38:36 ii : 'C:\Documents and Settings\organ\Мои документы\Shrew Soft VPN\certs\organca-cert.pem' loaded
10/06/23 09:38:36 <A : local cert 'C:\Documents and Settings\organ\Мои документы\Shrew Soft VPN\certs\rw2-cert.pem' message
10/06/23 09:38:36 ii : 'C:\Documents and Settings\organ\Мои документы\Shrew Soft VPN\certs\rw2-cert.pem' loaded
10/06/23 09:38:36 <A : local key 'C:\Documents and Settings\organ\Мои документы\Shrew Soft VPN\certs\rw2-key.pem' message
10/06/23 09:38:36 ii : 'C:\Documents and Settings\organ\Мои документы\Shrew Soft VPN\certs\rw2-key.pem' loaded
10/06/23 09:38:36 <A : remote resource message
10/06/23 09:38:36 <A : remote resource message
10/06/23 09:38:36 <A : peer tunnel enable message
10/06/23 09:38:36 ii : obtained x509 cert subject ( 125 bytes )
10/06/23 09:38:36 DB : new phase1 ( ISAKMP initiator )
10/06/23 09:38:36 DB : exchange type is identity protect
10/06/23 09:38:36 DB : 192.168.0.25:500 <-> 195.162.66.178:500
10/06/23 09:38:36 DB : 9ec59efe15fd0ef5:0000000000000000
10/06/23 09:38:36 DB : phase1 added ( obj count = 1 )
10/06/23 09:38:36 >> : security association payload
10/06/23 09:38:36 >> : - proposal #1 payload 
10/06/23 09:38:36 >> : -- transform #1 payload 
10/06/23 09:38:36 >> : -- transform #2 payload 
10/06/23 09:38:36 >> : -- transform #3 payload 
10/06/23 09:38:36 >> : -- transform #4 payload 
10/06/23 09:38:36 >> : -- transform #5 payload 
10/06/23 09:38:36 >> : -- transform #6 payload 
10/06/23 09:38:36 >> : -- transform #7 payload 
10/06/23 09:38:36 >> : -- transform #8 payload 
10/06/23 09:38:36 >> : -- transform #9 payload 
10/06/23 09:38:36 >> : -- transform #10 payload 
10/06/23 09:38:36 >> : -- transform #11 payload 
10/06/23 09:38:36 >> : -- transform #12 payload 
10/06/23 09:38:36 >> : -- transform #13 payload 
10/06/23 09:38:36 >> : -- transform #14 payload 
10/06/23 09:38:36 >> : -- transform #15 payload 
10/06/23 09:38:36 >> : -- transform #16 payload 
10/06/23 09:38:36 >> : -- transform #17 payload 
10/06/23 09:38:36 >> : -- transform #18 payload 
10/06/23 09:38:36 >> : -- transform #19 payload 
10/06/23 09:38:36 >> : -- transform #20 payload 
10/06/23 09:38:36 >> : -- transform #21 payload 
10/06/23 09:38:36 >> : -- transform #22 payload 
10/06/23 09:38:36 >> : -- transform #23 payload 
10/06/23 09:38:36 >> : -- transform #24 payload 
10/06/23 09:38:36 >> : -- transform #25 payload 
10/06/23 09:38:36 >> : -- transform #26 payload 
10/06/23 09:38:36 >> : -- transform #27 payload 
10/06/23 09:38:36 >> : -- transform #28 payload 
10/06/23 09:38:36 >> : -- transform #29 payload 
10/06/23 09:38:36 >> : -- transform #30 payload 
10/06/23 09:38:36 >> : -- transform #31 payload 
10/06/23 09:38:36 >> : -- transform #32 payload 
10/06/23 09:38:36 >> : -- transform #33 payload 
10/06/23 09:38:36 >> : -- transform #34 payload 
10/06/23 09:38:36 >> : -- transform #35 payload 
10/06/23 09:38:36 >> : -- transform #36 payload 
10/06/23 09:38:36 >> : -- transform #37 payload 
10/06/23 09:38:36 >> : -- transform #38 payload 
10/06/23 09:38:36 >> : -- transform #39 payload 
10/06/23 09:38:36 >> : -- transform #40 payload 
10/06/23 09:38:36 >> : -- transform #41 payload 
10/06/23 09:38:36 >> : -- transform #42 payload 
10/06/23 09:38:36 >> : -- transform #43 payload 
10/06/23 09:38:36 >> : -- transform #44 payload 
10/06/23 09:38:36 >> : -- transform #45 payload 
10/06/23 09:38:36 >> : -- transform #46 payload 
10/06/23 09:38:36 >> : -- transform #47 payload 
10/06/23 09:38:36 >> : -- transform #48 payload 
10/06/23 09:38:36 >> : -- transform #49 payload 
10/06/23 09:38:36 >> : -- transform #50 payload 
10/06/23 09:38:36 >> : -- transform #51 payload 
10/06/23 09:38:36 >> : -- transform #52 payload 
10/06/23 09:38:36 >> : -- transform #53 payload 
10/06/23 09:38:36 >> : -- transform #54 payload 
10/06/23 09:38:36 >> : -- transform #55 payload 
10/06/23 09:38:36 >> : -- transform #56 payload 
10/06/23 09:38:36 >> : -- transform #57 payload 
10/06/23 09:38:36 >> : -- transform #58 payload 
10/06/23 09:38:36 >> : -- transform #59 payload 
10/06/23 09:38:36 >> : -- transform #60 payload 
10/06/23 09:38:36 >> : -- transform #61 payload 
10/06/23 09:38:36 >> : -- transform #62 payload 
10/06/23 09:38:36 >> : -- transform #63 payload 
10/06/23 09:38:36 >> : -- transform #64 payload 
10/06/23 09:38:36 >> : -- transform #65 payload 
10/06/23 09:38:36 >> : -- transform #66 payload 
10/06/23 09:38:36 >> : -- transform #67 payload 
10/06/23 09:38:36 >> : -- transform #68 payload 
10/06/23 09:38:36 >> : -- transform #69 payload 
10/06/23 09:38:36 >> : -- transform #70 payload 
10/06/23 09:38:36 >> : -- transform #71 payload 
10/06/23 09:38:36 >> : -- transform #72 payload 
10/06/23 09:38:36 >> : -- transform #73 payload 
10/06/23 09:38:36 >> : -- transform #74 payload 
10/06/23 09:38:36 >> : -- transform #75 payload 
10/06/23 09:38:36 >> : -- transform #76 payload 
10/06/23 09:38:36 >> : -- transform #77 payload 
10/06/23 09:38:36 >> : -- transform #78 payload 
10/06/23 09:38:36 >> : -- transform #79 payload 
10/06/23 09:38:36 >> : -- transform #80 payload 
10/06/23 09:38:36 >> : -- transform #81 payload 
10/06/23 09:38:36 >> : -- transform #82 payload 
10/06/23 09:38:36 >> : -- transform #83 payload 
10/06/23 09:38:36 >> : -- transform #84 payload 
10/06/23 09:38:36 >> : -- transform #85 payload 
10/06/23 09:38:36 >> : -- transform #86 payload 
10/06/23 09:38:36 >> : -- transform #87 payload 
10/06/23 09:38:36 >> : -- transform #88 payload 
10/06/23 09:38:36 >> : -- transform #89 payload 
10/06/23 09:38:36 >> : -- transform #90 payload 
10/06/23 09:38:36 >> : vendor id payload
10/06/23 09:38:36 ii : local supports XAUTH
10/06/23 09:38:36 >> : vendor id payload
10/06/23 09:38:36 ii : local supports nat-t ( draft v00 )
10/06/23 09:38:36 >> : vendor id payload
10/06/23 09:38:36 ii : local supports nat-t ( draft v01 )
10/06/23 09:38:36 >> : vendor id payload
10/06/23 09:38:36 ii : local supports nat-t ( draft v02 )
10/06/23 09:38:36 >> : vendor id payload
10/06/23 09:38:36 ii : local supports nat-t ( draft v03 )
10/06/23 09:38:36 >> : vendor id payload
10/06/23 09:38:36 ii : local supports nat-t ( rfc )
10/06/23 09:38:36 >> : vendor id payload
10/06/23 09:38:36 ii : local supports FRAGMENTATION
10/06/23 09:38:36 >> : vendor id payload
10/06/23 09:38:36 ii : local supports DPDv1
10/06/23 09:38:36 >> : vendor id payload
10/06/23 09:38:36 ii : local is SHREW SOFT compatible
10/06/23 09:38:36 >> : vendor id payload
10/06/23 09:38:36 ii : local is NETSCREEN compatible
10/06/23 09:38:36 >> : vendor id payload
10/06/23 09:38:36 ii : local is SIDEWINDER compatible
10/06/23 09:38:36 >> : vendor id payload
10/06/23 09:38:36 ii : local is CISCO UNITY compatible
10/06/23 09:38:36 >= : cookies 9ec59efe15fd0ef5:0000000000000000
10/06/23 09:38:36 >= : message 00000000
10/06/23 09:38:36 -> : send IKE packet 192.168.0.25:500 -> 195.162.66.178:500 ( 3796 bytes )
10/06/23 09:38:36 ii : fragmented packet to 1514 bytes ( MTU 1500 bytes )
10/06/23 09:38:36 ii : fragmented packet to 1514 bytes ( MTU 1500 bytes )
10/06/23 09:38:36 ii : fragmented packet to 850 bytes ( MTU 1500 bytes )
10/06/23 09:38:36 DB : phase1 resend event scheduled ( ref count = 2 )
10/06/23 09:38:36 <- : recv IKE packet 195.162.66.178:500 -> 192.168.0.25:500 ( 180 bytes )
10/06/23 09:38:36 DB : phase1 found
10/06/23 09:38:36 ii : processing phase1 packet ( 180 bytes )
10/06/23 09:38:36 =< : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:36 =< : message 00000000
10/06/23 09:38:36 << : security association payload
10/06/23 09:38:36 << : - propsal #1 payload 
10/06/23 09:38:36 << : -- transform #1 payload 
10/06/23 09:38:36 ii : matched isakmp proposal #1 transform #1
10/06/23 09:38:36 ii : - transform    = ike
10/06/23 09:38:36 ii : - cipher type  = aes
10/06/23 09:38:36 ii : - key length   = 256 bits
10/06/23 09:38:36 ii : - hash type    = md5
10/06/23 09:38:36 ii : - dh group     = modp-3072
10/06/23 09:38:36 ii : - auth type    = xauth-initiator-rsa
10/06/23 09:38:36 ii : - life seconds = 86400
10/06/23 09:38:36 ii : - life kbytes  = 0
10/06/23 09:38:37 << : vendor id payload
10/06/23 09:38:37 ii : unknown vendor id ( 16 bytes )
10/06/23 09:38:37 0x : cd5792d4 b70f0299 a6a1373d e236d2ac
10/06/23 09:38:37 << : vendor id payload
10/06/23 09:38:37 ii : peer is CISCO UNITY compatible
10/06/23 09:38:37 << : vendor id payload
10/06/23 09:38:37 ii : peer supports XAUTH
10/06/23 09:38:37 << : vendor id payload
10/06/23 09:38:37 ii : peer supports DPDv1
10/06/23 09:38:37 << : vendor id payload
10/06/23 09:38:37 ii : peer supports nat-t ( rfc )
10/06/23 09:38:37 >> : key exchange payload
10/06/23 09:38:37 >> : nonce payload
10/06/23 09:38:37 >> : cert request payload
10/06/23 09:38:37 >> : nat discovery payload
10/06/23 09:38:37 >> : nat discovery payload
10/06/23 09:38:37 >= : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:37 >= : message 00000000
10/06/23 09:38:37 DB : phase1 resend event canceled ( ref count = 1 )
10/06/23 09:38:37 -> : send IKE packet 192.168.0.25:500 -> 195.162.66.178:500 ( 513 bytes )
10/06/23 09:38:37 DB : phase1 resend event scheduled ( ref count = 2 )
10/06/23 09:38:37 <- : recv IKE packet 195.162.66.178:500 -> 192.168.0.25:500 ( 484 bytes )
10/06/23 09:38:37 DB : phase1 found
10/06/23 09:38:37 ii : processing phase1 packet ( 484 bytes )
10/06/23 09:38:37 =< : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:37 =< : message 00000000
10/06/23 09:38:37 << : key exchange payload
10/06/23 09:38:37 << : nonce payload
10/06/23 09:38:37 << : cert request payload
10/06/23 09:38:37 << : nat discovery payload
10/06/23 09:38:37 << : nat discovery payload
10/06/23 09:38:37 ii : nat discovery - local address is translated
10/06/23 09:38:37 ii : switching to src nat-t udp port 4500
10/06/23 09:38:37 ii : switching to dst nat-t udp port 4500
10/06/23 09:38:38 == : DH shared secret ( 384 bytes )
10/06/23 09:38:38 == : SETKEYID ( 16 bytes )
10/06/23 09:38:38 == : SETKEYID_d ( 16 bytes )
10/06/23 09:38:38 == : SETKEYID_a ( 16 bytes )
10/06/23 09:38:38 == : SETKEYID_e ( 16 bytes )
10/06/23 09:38:38 == : cipher key ( 32 bytes )
10/06/23 09:38:38 == : cipher iv ( 16 bytes )
10/06/23 09:38:38 >> : identification payload
10/06/23 09:38:38 >> : certificate payload
10/06/23 09:38:38 == : phase1 hash_i ( computed ) ( 16 bytes )
10/06/23 09:38:38 >> : signature payload
10/06/23 09:38:38 >= : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:38 >= : message 00000000
10/06/23 09:38:38 >= : encrypt iv ( 16 bytes )
10/06/23 09:38:38 == : encrypt packet ( 1491 bytes )
10/06/23 09:38:38 == : stored iv ( 16 bytes )
10/06/23 09:38:38 DB : phase1 resend event canceled ( ref count = 1 )
10/06/23 09:38:38 -> : send NAT-T:IKE packet 192.168.0.25:4500 -> 195.162.66.178:4500 ( 1532 bytes )
10/06/23 09:38:38 ii : fragmented packet to 1514 bytes ( MTU 1500 bytes )
10/06/23 09:38:38 ii : fragmented packet to 66 bytes ( MTU 1500 bytes )
10/06/23 09:38:38 <- : recv NAT-T:IKE packet 195.162.66.178:4500 -> 192.168.0.25:4500 ( 1548 bytes )
10/06/23 09:38:38 DB : phase1 found
10/06/23 09:38:38 ii : processing phase1 packet ( 1548 bytes )
10/06/23 09:38:38 =< : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:38 =< : message 00000000
10/06/23 09:38:38 =< : decrypt iv ( 16 bytes )
10/06/23 09:38:38 == : decrypt packet ( 1548 bytes )
10/06/23 09:38:38 <= : trimmed packet padding ( 6 bytes )
10/06/23 09:38:38 <= : stored iv ( 16 bytes )
10/06/23 09:38:38 << : identification payload
10/06/23 09:38:38 ii : phase1 id target is any
10/06/23 09:38:38 ii : phase1 id match 
10/06/23 09:38:38 ii : received = asn1-dn C=RU,ST=Tomsk region,O=organ,OU=Central Office,CN=gw.openorgan.ru,emailAddress=gateway at openorgan.ru
10/06/23 09:38:38 << : certificate payload
10/06/23 09:38:38 << : signature payload
10/06/23 09:38:38 ii : added ca-cert.pem to x509 store
10/06/23 09:38:38 ii : added rw2-cert.pem to x509 store
10/06/23 09:38:38 ii : unable to get certificate CRL(3) at depth:0
10/06/23 09:38:38 ii : subject :/C=RU/ST=Tomsk region/O=organ/OU=Central Office/CN=gw.openorgan.ru/emailAddress=gateway at openorgan.ru
10/06/23 09:38:38 ii : unable to get certificate CRL(3) at depth:1
10/06/23 09:38:38 ii : subject :/C=RU/ST=Tomsk region/O=organ Ltd/OU=Central Office/CN=organ CA/emailAddress=postmaster at openorgan.ru
10/06/23 09:38:38 == : phase1 hash_r ( computed ) ( 16 bytes )
10/06/23 09:38:38 == : phase1 hash_r ( received ) ( 16 bytes )
10/06/23 09:38:38 ii : phase1 sa established
10/06/23 09:38:38 ii : 195.162.66.178:4500 <-> 192.168.0.25:4500
10/06/23 09:38:38 ii : 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:38 ii : sending peer INITIAL-CONTACT notification
10/06/23 09:38:38 ii : - 192.168.0.25:4500 -> 195.162.66.178:4500
10/06/23 09:38:38 ii : - isakmp spi = 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:38 ii : - data size 0
10/06/23 09:38:38 >> : hash payload
10/06/23 09:38:38 >> : notification payload
10/06/23 09:38:38 == : new informational hash ( 16 bytes )
10/06/23 09:38:38 == : new informational iv ( 16 bytes )
10/06/23 09:38:38 >= : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:38 >= : message 93c66872
10/06/23 09:38:38 >= : encrypt iv ( 16 bytes )
10/06/23 09:38:38 == : encrypt packet ( 76 bytes )
10/06/23 09:38:38 == : stored iv ( 16 bytes )
10/06/23 09:38:38 -> : send NAT-T:IKE packet 192.168.0.25:4500 -> 195.162.66.178:4500 ( 108 bytes )
10/06/23 09:38:38 DB : phase2 not found
10/06/23 09:38:38 <- : recv NAT-T:IKE packet 195.162.66.178:4500 -> 192.168.0.25:4500 ( 76 bytes )
10/06/23 09:38:38 DB : phase1 found
10/06/23 09:38:38 ii : processing config packet ( 76 bytes )
10/06/23 09:38:38 DB : config not found
10/06/23 09:38:38 DB : config added ( obj count = 1 )
10/06/23 09:38:38 == : new config iv ( 16 bytes )
10/06/23 09:38:38 =< : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:38 =< : message ebd211a2
10/06/23 09:38:38 =< : decrypt iv ( 16 bytes )
10/06/23 09:38:38 == : decrypt packet ( 76 bytes )
10/06/23 09:38:38 <= : trimmed packet padding ( 12 bytes )
10/06/23 09:38:38 <= : stored iv ( 16 bytes )
10/06/23 09:38:38 << : hash payload
10/06/23 09:38:38 << : attribute payload
10/06/23 09:38:38 == : configure hash_i ( computed ) ( 16 bytes )
10/06/23 09:38:38 == : configure hash_c ( computed ) ( 16 bytes )
10/06/23 09:38:38 ii : configure hash verified
10/06/23 09:38:38 ii : - xauth username
10/06/23 09:38:38 ii : - xauth password
10/06/23 09:38:38 ii : received basic xauth request - 
10/06/23 09:38:38 ii : - standard xauth username
10/06/23 09:38:38 ii : - standard xauth password
10/06/23 09:38:38 ii : sending xauth response for smirnovm
10/06/23 09:38:38 >> : hash payload
10/06/23 09:38:38 >> : attribute payload
10/06/23 09:38:38 == : new configure hash ( 16 bytes )
10/06/23 09:38:38 >= : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:38 >= : message ebd211a2
10/06/23 09:38:38 >= : encrypt iv ( 16 bytes )
10/06/23 09:38:38 == : encrypt packet ( 81 bytes )
10/06/23 09:38:38 == : stored iv ( 16 bytes )
10/06/23 09:38:38 -> : send NAT-T:IKE packet 192.168.0.25:4500 -> 195.162.66.178:4500 ( 124 bytes )
10/06/23 09:38:38 DB : config resend event scheduled ( ref count = 2 )
10/06/23 09:38:38 <- : recv NAT-T:IKE packet 195.162.66.178:4500 -> 192.168.0.25:4500 ( 60 bytes )
10/06/23 09:38:38 DB : phase1 found
10/06/23 09:38:38 ii : processing config packet ( 60 bytes )
10/06/23 09:38:38 DB : config found
10/06/23 09:38:38 == : new config iv ( 16 bytes )
10/06/23 09:38:38 =< : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:38 =< : message 288845a4
10/06/23 09:38:38 =< : decrypt iv ( 16 bytes )
10/06/23 09:38:38 == : decrypt packet ( 60 bytes )
10/06/23 09:38:38 <= : stored iv ( 16 bytes )
10/06/23 09:38:38 << : hash payload
10/06/23 09:38:38 << : attribute payload
10/06/23 09:38:38 == : configure hash_i ( computed ) ( 16 bytes )
10/06/23 09:38:38 == : configure hash_c ( computed ) ( 16 bytes )
10/06/23 09:38:38 ii : configure hash verified
10/06/23 09:38:38 ii : received xauth result - 
10/06/23 09:38:38 ii : user smirnovm authentication succeeded
10/06/23 09:38:38 ii : sending xauth acknowledge
10/06/23 09:38:38 >> : hash payload
10/06/23 09:38:38 >> : attribute payload
10/06/23 09:38:38 == : new configure hash ( 16 bytes )
10/06/23 09:38:38 >= : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:38 >= : message 288845a4
10/06/23 09:38:38 >= : encrypt iv ( 16 bytes )
10/06/23 09:38:38 == : encrypt packet ( 56 bytes )
10/06/23 09:38:38 == : stored iv ( 16 bytes )
10/06/23 09:38:38 DB : config resend event canceled ( ref count = 1 )
10/06/23 09:38:38 -> : send NAT-T:IKE packet 192.168.0.25:4500 -> 195.162.66.178:4500 ( 92 bytes )
10/06/23 09:38:38 DB : config resend event scheduled ( ref count = 2 )
10/06/23 09:38:38 ii : building config attribute list
10/06/23 09:38:38 ii : - IP4 Address
10/06/23 09:38:38 ii : - Address Expiry
10/06/23 09:38:38 ii : - IP4 Netamask
10/06/23 09:38:38 ii : - IP4 DNS Server
10/06/23 09:38:38 ii : - IP4 WINS Server
10/06/23 09:38:38 ii : - DNS Suffix
10/06/23 09:38:38 ii : - Split DNS Domain
10/06/23 09:38:38 ii : - Login Banner
10/06/23 09:38:38 ii : - Save Password
10/06/23 09:38:38 == : new config iv ( 16 bytes )
10/06/23 09:38:38 ii : sending config pull request
10/06/23 09:38:38 >> : hash payload
10/06/23 09:38:38 >> : attribute payload
10/06/23 09:38:38 == : new configure hash ( 16 bytes )
10/06/23 09:38:38 >= : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:38 >= : message c123c3b2
10/06/23 09:38:38 >= : encrypt iv ( 16 bytes )
10/06/23 09:38:38 == : encrypt packet ( 92 bytes )
10/06/23 09:38:38 == : stored iv ( 16 bytes )
10/06/23 09:38:38 DB : config resend event canceled ( ref count = 1 )
10/06/23 09:38:38 -> : send NAT-T:IKE packet 192.168.0.25:4500 -> 195.162.66.178:4500 ( 124 bytes )
10/06/23 09:38:38 DB : config resend event scheduled ( ref count = 2 )
10/06/23 09:38:38 <- : recv NAT-T:IKE packet 195.162.66.178:4500 -> 192.168.0.25:4500 ( 124 bytes )
10/06/23 09:38:38 DB : phase1 found
10/06/23 09:38:38 ii : processing config packet ( 124 bytes )
10/06/23 09:38:38 DB : config found
10/06/23 09:38:38 =< : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:38 =< : message c123c3b2
10/06/23 09:38:38 =< : decrypt iv ( 16 bytes )
10/06/23 09:38:38 == : decrypt packet ( 124 bytes )
10/06/23 09:38:38 <= : stored iv ( 16 bytes )
10/06/23 09:38:38 << : hash payload
10/06/23 09:38:38 << : attribute payload
10/06/23 09:38:38 == : configure hash_i ( computed ) ( 16 bytes )
10/06/23 09:38:38 == : configure hash_c ( computed ) ( 16 bytes )
10/06/23 09:38:38 ii : configure hash verified
10/06/23 09:38:38 ii : received config pull response
10/06/23 09:38:38 ii : - IP4 Address = 192.168.255.2
10/06/23 09:38:38 ii : - IP4 Netmask = 255.255.255.255
10/06/23 09:38:38 ii : - Login Banner = Welcome to stro ...
10/06/23 09:38:38 DB : config resend event canceled ( ref count = 1 )
10/06/23 09:38:51 ii : VNET adapter MTU is 1500
10/06/23 09:38:51 ii : enabled adapter ROOT\VNET\0000
10/06/23 09:38:51 ii : creating IPSEC INBOUND policy ANY:192.168.0.0/24:* -> ANY:192.168.255.2:*
10/06/23 09:38:51 DB : policy added ( obj count = 4 )
10/06/23 09:38:51 K> : send pfkey X_SPDADD UNSPEC message
10/06/23 09:38:51 K< : recv pfkey X_SPDADD UNSPEC message
10/06/23 09:38:51 DB : policy found
10/06/23 09:38:51 ii : creating IPSEC OUTBOUND policy ANY:192.168.255.2:* -> ANY:192.168.0.0/24:*
10/06/23 09:38:52 ii : created IPSEC policy route for 192.168.0.0/24
10/06/23 09:38:52 DB : policy added ( obj count = 5 )
10/06/23 09:38:52 K> : send pfkey X_SPDADD UNSPEC message
10/06/23 09:38:52 ii : creating IPSEC INBOUND policy ANY:195.162.56.224/29:* -> ANY:192.168.255.2:*
10/06/23 09:38:52 DB : policy added ( obj count = 6 )
10/06/23 09:38:52 K> : send pfkey X_SPDADD UNSPEC message
10/06/23 09:38:52 ii : creating IPSEC OUTBOUND policy ANY:192.168.255.2:* -> ANY:195.162.56.224/29:*
10/06/23 09:38:52 ii : created IPSEC policy route for 195.162.56.224/29
10/06/23 09:38:52 DB : policy added ( obj count = 7 )
10/06/23 09:38:52 K> : send pfkey X_SPDADD UNSPEC message
10/06/23 09:38:52 ii : split DNS bypassed ( no split domains defined )
10/06/23 09:38:53 K< : recv pfkey X_SPDADD UNSPEC message
10/06/23 09:38:53 DB : policy found
10/06/23 09:38:53 ii : calling init phase2 for initial policy
10/06/23 09:38:53 DB : policy found
10/06/23 09:38:53 DB : policy found
10/06/23 09:38:53 DB : tunnel found
10/06/23 09:38:53 DB : new phase2 ( IPSEC initiator )
10/06/23 09:38:53 DB : phase2 added ( obj count = 1 )
10/06/23 09:38:53 K> : send pfkey GETSPI ESP message
10/06/23 09:38:53 K< : recv pfkey X_SPDADD UNSPEC message
10/06/23 09:38:53 DB : policy found
10/06/23 09:38:53 K< : recv pfkey X_SPDADD UNSPEC message
10/06/23 09:38:53 DB : policy found
10/06/23 09:38:53 K< : recv pfkey GETSPI ESP message
10/06/23 09:38:53 DB : phase2 found
10/06/23 09:38:53 ii : updated spi for 1 ipsec-esp proposal
10/06/23 09:38:53 DB : phase1 found
10/06/23 09:38:53 >> : hash payload
10/06/23 09:38:53 >> : security association payload
10/06/23 09:38:53 >> : - proposal #1 payload 
10/06/23 09:38:53 >> : -- transform #1 payload 
10/06/23 09:38:53 >> : -- transform #2 payload 
10/06/23 09:38:53 >> : -- transform #3 payload 
10/06/23 09:38:53 >> : -- transform #4 payload 
10/06/23 09:38:53 >> : -- transform #5 payload 
10/06/23 09:38:53 >> : -- transform #6 payload 
10/06/23 09:38:53 >> : -- transform #7 payload 
10/06/23 09:38:53 >> : -- transform #8 payload 
10/06/23 09:38:53 >> : -- transform #9 payload 
10/06/23 09:38:53 >> : -- transform #10 payload 
10/06/23 09:38:53 >> : -- transform #11 payload 
10/06/23 09:38:53 >> : -- transform #12 payload 
10/06/23 09:38:53 >> : -- transform #13 payload 
10/06/23 09:38:53 >> : -- transform #14 payload 
10/06/23 09:38:53 >> : -- transform #15 payload 
10/06/23 09:38:53 >> : -- transform #16 payload 
10/06/23 09:38:53 >> : -- transform #17 payload 
10/06/23 09:38:53 >> : -- transform #18 payload 
10/06/23 09:38:53 >> : nonce payload
10/06/23 09:38:53 >> : key exchange payload
10/06/23 09:38:53 >> : identification payload
10/06/23 09:38:53 >> : identification payload
10/06/23 09:38:53 == : phase2 hash_i ( input ) ( 836 bytes )
10/06/23 09:38:53 == : phase2 hash_i ( computed ) ( 16 bytes )
10/06/23 09:38:53 == : new phase2 iv ( 16 bytes )
10/06/23 09:38:53 >= : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:53 >= : message cae86740
10/06/23 09:38:53 >= : encrypt iv ( 16 bytes )
10/06/23 09:38:53 == : encrypt packet ( 880 bytes )
10/06/23 09:38:53 == : stored iv ( 16 bytes )
10/06/23 09:38:53 -> : send NAT-T:IKE packet 192.168.0.25:4500 -> 195.162.66.178:4500 ( 924 bytes )
10/06/23 09:38:53 DB : phase2 resend event scheduled ( ref count = 2 )
10/06/23 09:38:53 DB : phase1 found
10/06/23 09:38:53 ii : sending peer DPDV1-R-U-THERE notification
10/06/23 09:38:53 ii : - 192.168.0.25:4500 -> 195.162.66.178:4500
10/06/23 09:38:53 ii : - isakmp spi = 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:53 ii : - data size 4
10/06/23 09:38:53 >> : hash payload
10/06/23 09:38:53 >> : notification payload
10/06/23 09:38:53 == : new informational hash ( 16 bytes )
10/06/23 09:38:53 == : new informational iv ( 16 bytes )
10/06/23 09:38:53 >= : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:38:53 >= : message 648b8432
10/06/23 09:38:53 >= : encrypt iv ( 16 bytes )
10/06/23 09:38:53 == : encrypt packet ( 80 bytes )
10/06/23 09:38:53 == : stored iv ( 16 bytes )
10/06/23 09:38:53 -> : send NAT-T:IKE packet 192.168.0.25:4500 -> 195.162.66.178:4500 ( 124 bytes )
10/06/23 09:38:53 ii : DPD ARE-YOU-THERE sequence 2ba75998 requested
10/06/23 09:38:53 DB : phase1 found
10/06/23 09:38:53 -> : send NAT-T:KEEP-ALIVE packet 192.168.0.25:4500 -> 195.162.66.178:4500
10/06/23 09:38:58 -> : resend 1 phase2 packet(s) 192.168.0.25:4500 -> 195.162.66.178:4500
10/06/23 09:39:03 -> : resend 1 phase2 packet(s) 192.168.0.25:4500 -> 195.162.66.178:4500
10/06/23 09:39:08 -> : resend 1 phase2 packet(s) 192.168.0.25:4500 -> 195.162.66.178:4500
10/06/23 09:39:08 DB : phase1 found
10/06/23 09:39:08 -> : send NAT-T:KEEP-ALIVE packet 192.168.0.25:4500 -> 195.162.66.178:4500
10/06/23 09:39:08 DB : phase1 found
10/06/23 09:39:08 ii : next tunnel DPD retry in 4 secs for peer 195.162.66.178:4500
10/06/23 09:39:08 ii : sending peer DPDV1-R-U-THERE notification
10/06/23 09:39:08 ii : - 192.168.0.25:4500 -> 195.162.66.178:4500
10/06/23 09:39:08 ii : - isakmp spi = 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:39:08 ii : - data size 4
10/06/23 09:39:08 >> : hash payload
10/06/23 09:39:08 >> : notification payload
10/06/23 09:39:08 == : new informational hash ( 16 bytes )
10/06/23 09:39:08 == : new informational iv ( 16 bytes )
10/06/23 09:39:08 >= : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:39:08 >= : message 5a8e4cb4
10/06/23 09:39:08 >= : encrypt iv ( 16 bytes )
10/06/23 09:39:08 == : encrypt packet ( 80 bytes )
10/06/23 09:39:08 == : stored iv ( 16 bytes )
10/06/23 09:39:08 -> : send NAT-T:IKE packet 192.168.0.25:4500 -> 195.162.66.178:4500 ( 124 bytes )
10/06/23 09:39:08 ii : DPD ARE-YOU-THERE sequence 2ba75999 requested
10/06/23 09:39:12 DB : phase1 found
10/06/23 09:39:12 ii : next tunnel DPD retry in 3 secs for peer 195.162.66.178:4500
10/06/23 09:39:12 ii : sending peer DPDV1-R-U-THERE notification
10/06/23 09:39:12 ii : - 192.168.0.25:4500 -> 195.162.66.178:4500
10/06/23 09:39:12 ii : - isakmp spi = 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:39:12 ii : - data size 4
10/06/23 09:39:12 >> : hash payload
10/06/23 09:39:12 >> : notification payload
10/06/23 09:39:12 == : new informational hash ( 16 bytes )
10/06/23 09:39:12 == : new informational iv ( 16 bytes )
10/06/23 09:39:12 >= : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:39:12 >= : message c3574b54
10/06/23 09:39:12 >= : encrypt iv ( 16 bytes )
10/06/23 09:39:12 == : encrypt packet ( 80 bytes )
10/06/23 09:39:12 == : stored iv ( 16 bytes )
10/06/23 09:39:12 -> : send NAT-T:IKE packet 192.168.0.25:4500 -> 195.162.66.178:4500 ( 124 bytes )
10/06/23 09:39:12 ii : DPD ARE-YOU-THERE sequence 2ba7599a requested
10/06/23 09:39:13 ii : resend limit exceeded for phase2 exchange
10/06/23 09:39:13 ii : phase2 removal before expire time
10/06/23 09:39:13 DB : phase2 deleted ( obj count = 0 )
10/06/23 09:39:15 DB : phase1 found
10/06/23 09:39:15 ii : next tunnel DPD retry in 2 secs for peer 195.162.66.178:4500
10/06/23 09:39:15 ii : sending peer DPDV1-R-U-THERE notification
10/06/23 09:39:15 ii : - 192.168.0.25:4500 -> 195.162.66.178:4500
10/06/23 09:39:15 ii : - isakmp spi = 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:39:15 ii : - data size 4
10/06/23 09:39:15 >> : hash payload
10/06/23 09:39:15 >> : notification payload
10/06/23 09:39:15 == : new informational hash ( 16 bytes )
10/06/23 09:39:15 == : new informational iv ( 16 bytes )
10/06/23 09:39:15 >= : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:39:15 >= : message 1b3f9b1a
10/06/23 09:39:15 >= : encrypt iv ( 16 bytes )
10/06/23 09:39:15 == : encrypt packet ( 80 bytes )
10/06/23 09:39:15 == : stored iv ( 16 bytes )
10/06/23 09:39:15 -> : send NAT-T:IKE packet 192.168.0.25:4500 -> 195.162.66.178:4500 ( 124 bytes )
10/06/23 09:39:15 ii : DPD ARE-YOU-THERE sequence 2ba7599b requested
10/06/23 09:39:17 DB : phase1 found
10/06/23 09:39:17 ii : next tunnel DPD retry in 1 secs for peer 195.162.66.178:4500
10/06/23 09:39:17 ii : sending peer DPDV1-R-U-THERE notification
10/06/23 09:39:17 ii : - 192.168.0.25:4500 -> 195.162.66.178:4500
10/06/23 09:39:17 ii : - isakmp spi = 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:39:17 ii : - data size 4
10/06/23 09:39:17 >> : hash payload
10/06/23 09:39:17 >> : notification payload
10/06/23 09:39:17 == : new informational hash ( 16 bytes )
10/06/23 09:39:17 == : new informational iv ( 16 bytes )
10/06/23 09:39:17 >= : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:39:17 >= : message 6abc4117
10/06/23 09:39:17 >= : encrypt iv ( 16 bytes )
10/06/23 09:39:17 == : encrypt packet ( 80 bytes )
10/06/23 09:39:17 == : stored iv ( 16 bytes )
10/06/23 09:39:17 -> : send NAT-T:IKE packet 192.168.0.25:4500 -> 195.162.66.178:4500 ( 124 bytes )
10/06/23 09:39:17 ii : DPD ARE-YOU-THERE sequence 2ba7599c requested
10/06/23 09:39:18 !! : tunnel DPD timeout for peer 195.162.66.178:4500
10/06/23 09:39:18 DB : policy found
10/06/23 09:39:18 ii : removing IPSEC INBOUND policy ANY:192.168.0.0/24:* -> ANY:192.168.255.2:*
10/06/23 09:39:18 K> : send pfkey X_SPDDELETE2 UNSPEC message
10/06/23 09:39:18 DB : policy found
10/06/23 09:39:18 ii : removing IPSEC OUTBOUND policy ANY:192.168.255.2:* -> ANY:192.168.0.0/24:*
10/06/23 09:39:18 K> : send pfkey X_SPDDELETE2 UNSPEC message
10/06/23 09:39:18 DB : policy found
10/06/23 09:39:18 ii : removing IPSEC INBOUND policy ANY:195.162.56.224/29:* -> ANY:192.168.255.2:*
10/06/23 09:39:18 K< : recv pfkey X_SPDDELETE2 UNSPEC message
10/06/23 09:39:18 K> : send pfkey X_SPDDELETE2 UNSPEC message
10/06/23 09:39:18 DB : policy found
10/06/23 09:39:18 ii : removing IPSEC OUTBOUND policy ANY:192.168.255.2:* -> ANY:195.162.56.224/29:*
10/06/23 09:39:18 K> : send pfkey X_SPDDELETE2 UNSPEC message
10/06/23 09:39:18 DB : policy found
10/06/23 09:39:18 DB : policy deleted ( obj count = 6 )
10/06/23 09:39:18 K< : recv pfkey X_SPDDELETE2 UNSPEC message
10/06/23 09:39:18 DB : policy found
10/06/23 09:39:18 DB : policy deleted ( obj count = 5 )
10/06/23 09:39:18 K< : recv pfkey X_SPDDELETE2 UNSPEC message
10/06/23 09:39:18 DB : policy found
10/06/23 09:39:18 DB : policy deleted ( obj count = 4 )
10/06/23 09:39:19 K< : recv pfkey X_SPDDELETE2 UNSPEC message
10/06/23 09:39:19 DB : policy found
10/06/23 09:39:19 DB : policy deleted ( obj count = 3 )
10/06/23 09:39:19 ii : disabled adapter ROOT\VNET\0000
10/06/23 09:39:19 DB : tunnel natt event canceled ( ref count = 4 )
10/06/23 09:39:19 DB : tunnel stats event canceled ( ref count = 3 )
10/06/23 09:39:19 DB : removing tunnel config references
10/06/23 09:39:19 DB : config deleted ( obj count = 0 )
10/06/23 09:39:19 DB : removing tunnel phase2 references
10/06/23 09:39:19 DB : removing tunnel phase1 references
10/06/23 09:39:19 DB : phase1 soft event canceled ( ref count = 3 )
10/06/23 09:39:19 DB : phase1 hard event canceled ( ref count = 2 )
10/06/23 09:39:19 DB : phase1 dead event canceled ( ref count = 1 )
10/06/23 09:39:19 ii : sending peer DELETE message
10/06/23 09:39:19 ii : - 192.168.0.25:4500 -> 195.162.66.178:4500
10/06/23 09:39:19 ii : - isakmp spi = 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:39:19 ii : - data size 0
10/06/23 09:39:19 >> : hash payload
10/06/23 09:39:19 >> : delete payload
10/06/23 09:39:19 == : new informational hash ( 16 bytes )
10/06/23 09:39:19 == : new informational iv ( 16 bytes )
10/06/23 09:39:19 >= : cookies 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:39:19 >= : message bcdc878a
10/06/23 09:39:19 >= : encrypt iv ( 16 bytes )
10/06/23 09:39:19 == : encrypt packet ( 76 bytes )
10/06/23 09:39:19 == : stored iv ( 16 bytes )
10/06/23 09:39:19 -> : send NAT-T:IKE packet 192.168.0.25:4500 -> 195.162.66.178:4500 ( 108 bytes )
10/06/23 09:39:19 ii : phase1 removal before expire time
10/06/23 09:39:19 DB : phase1 deleted ( obj count = 0 )
10/06/23 09:39:19 DB : tunnel deleted ( obj count = 0 )
10/06/23 09:39:19 <- : recv NAT-T:IKE packet 195.162.66.178:4500 -> 192.168.0.25:4500 ( 76 bytes )
10/06/23 09:39:19 DB : phase1 not found
10/06/23 09:39:19 ww : ike packet from 195.162.66.178 ignored, unknown phase1 sa for peer
10/06/23 09:39:19 ww : 9ec59efe15fd0ef5:6e150e79e6cbee48
10/06/23 09:39:19 DB : removing all peer tunnel refrences
10/06/23 09:39:19 DB : peer deleted ( obj count = 0 )
10/06/23 09:39:19 ii : ipc client process thread exit ...
=========

=========
pluto[1372]: packet from 195.162.66.179:500: received Vendor ID payload [XAUTH]
pluto[1372]: packet from 195.162.66.179:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-00]
pluto[1372]: packet from 195.162.66.179:500: ignoring Vendor ID payload [16f6ca16e4a4066d83821a0f0aeaa862]
pluto[1372]: packet from 195.162.66.179:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-02_n]
pluto[1372]: packet from 195.162.66.179:500: received Vendor ID payload [draft-ietf-ipsec-nat-t-ike-03]
pluto[1372]: packet from 195.162.66.179:500: received Vendor ID payload [RFC 3947]
pluto[1372]: packet from 195.162.66.179:500: ignoring Vendor ID payload [FRAGMENTATION 80000000]
pluto[1372]: packet from 195.162.66.179:500: received Vendor ID payload [Dead Peer Detection]
pluto[1372]: packet from 195.162.66.179:500: ignoring Vendor ID payload [f14b94b7bff1fef02773b8c49feded26]
pluto[1372]: packet from 195.162.66.179:500: ignoring Vendor ID payload [166f932d55eb64d8e4df4fd37e2313f0d0fd8451]
pluto[1372]: packet from 195.162.66.179:500: ignoring Vendor ID payload [8404adf9cda05760b2ca292e4bff537b]
pluto[1372]: packet from 195.162.66.179:500: ignoring Vendor ID payload [Cisco-Unity]
pluto[1372]: "rw2"[22] 195.162.66.179 #44: responding to Main Mode from unknown peer 195.162.66.179
pluto[1372]: "rw2"[22] 195.162.66.179 #44: NAT-Traversal: Result using RFC 3947: peer is NATed
pluto[1372]: "rw2"[22] 195.162.66.179 #44: Peer ID is ID_DER_ASN1_DN: 'C=RU, ST=Tomsk region, O=organ, OU=Central Office, CN=rw2, E=rw2 at openorgan.ru'
pluto[1372]: "rw2"[22] 195.162.66.179 #44: crl not found
pluto[1372]: "rw2"[22] 195.162.66.179 #44: certificate status unknown
pluto[1372]: "rw2"[22] 195.162.66.179 #44: we have a cert and are sending it upon request
pluto[1372]: "rw2"[22] 195.162.66.179:4500 #44: sent MR3, ISAKMP SA established
pluto[1372]: "rw2"[22] 195.162.66.179:4500 #44: sending XAUTH request
pluto[1372]: packet from 195.162.66.179:4500: Informational Exchange is for an unknown (expired?) SA
pluto[1372]: "rw2"[22] 195.162.66.179:4500 #44: parsing XAUTH reply
pluto[1372]: "rw2"[22] 195.162.66.179:4500 #44: extended authentication was successful
pluto[1372]: "rw2"[22] 195.162.66.179:4500 #44: sending XAUTH status:
pluto[1372]: "rw2"[22] 195.162.66.179:4500 #44: parsing XAUTH ack
pluto[1372]: "rw2"[22] 195.162.66.179:4500 #44: received XAUTH ack, established
pluto[1372]: "rw2"[22] 195.162.66.179:4500 #44: assigning virtual IP source address 192.168.255.2
pluto[1372]: "rw2"[22] 195.162.66.179:4500 #44: sending ModeCfg reply
pluto[1372]: "rw2"[22] 195.162.66.179:4500 #44: sent ModeCfg reply, established
=========




More information about the vpn-help mailing list