2017-03-31 22:22:11: INFO: @(#)ipsec-tools 0.8.1 (http://ipsec-tools.sourceforge.net)
2017-03-31 22:22:11: INFO: @(#)This product linked OpenSSL 1.0.1g 7 Apr 2014 (http://www.openssl.org/)
2017-03-31 22:22:11: INFO: Reading configuration from "/var/run/racoon.conf"
2017-03-31 22:22:11: INFO: 10.0.0.1[4500] used for NAT-T
2017-03-31 22:22:11: INFO: 10.0.0.1[4500] used as isakmp port (fd=5)
2017-03-31 22:22:11: INFO: 10.0.0.1[500] used for NAT-T
2017-03-31 22:22:11: INFO: 10.0.0.1[500] used as isakmp port (fd=6)
2017-03-31 22:22:39: INFO: respond new phase 1 negotiation: 10.0.0.1[500]<=>10.2.128.240[500]
2017-03-31 22:22:39: INFO: begin Identity Protection mode.
2017-03-31 22:22:39: INFO: received Vendor ID: DPD
2017-03-31 22:22:39: INFO: received Vendor ID: FRAGMENTATION
2017-03-31 22:22:39: INFO: received Vendor ID: RFC 3947
2017-03-31 22:22:39: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-03
2017-03-31 22:22:39: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-02

2017-03-31 22:22:39: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-02
2017-03-31 22:22:39: [10.2.128.240] INFO: Selected NAT-T version: RFC 3947
2017-03-31 22:22:39: [10.0.0.1] INFO: Hashing 10.0.0.1[500] with algo #2 
2017-03-31 22:22:39: INFO: NAT-D payload #0 doesn't match
2017-03-31 22:22:39: [10.2.128.240] INFO: Hashing 10.2.128.240[500] with algo #2 
2017-03-31 22:22:39: INFO: NAT-D payload #1 verified
2017-03-31 22:22:39: INFO: NAT detected: ME 
2017-03-31 22:22:39: [10.2.128.240] INFO: Hashing 10.2.128.240[500] with algo #2 
2017-03-31 22:22:39: [10.0.0.1] INFO: Hashing 10.0.0.1[500] with algo #2 
2017-03-31 22:22:39: INFO: Adding remote and local NAT-D payloads.
2017-03-31 22:22:39: INFO: NAT-T: ports changed to: 10.2.128.240[4500]<->10.0.0.1[4500]
2017-03-31 22:22:39: INFO: KA list add: 10.0.0.1[4500]->10.2.128.240[4500]
2017-03-31 22:23:29: ERROR: phase1 negotiation failed due to time up. e871dfb10dd4c5ea:47ef885a6fe02919
2017-03-31 22:23:29: INFO: KA remove: 10.0.0.1[4500]->10.2.128.240[4500]
2017-03-31 22:23:30: INFO: respond new phase 1 negotiation: 10.0.0.1[500]<=>10.2.128.240[500]
2017-03-31 22:23:30: INFO: begin Identity Protection mode.
2017-03-31 22:23:30: INFO: received Vendor ID: DPD
2017-03-31 22:23:30: INFO: received Vendor ID: FRAGMENTATION
2017-03-31 22:23:30: INFO: received Vendor ID: RFC 3947
2017-03-31 22:23:30: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-03
2017-03-31 22:23:30: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-02

2017-03-31 22:23:30: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-02
2017-03-31 22:23:30: [10.2.128.240] INFO: Selected NAT-T version: RFC 3947
2017-03-31 22:23:30: [10.0.0.1] INFO: Hashing 10.0.0.1[500] with algo #2 
2017-03-31 22:23:30: INFO: NAT-D payload #0 doesn't match
2017-03-31 22:23:30: [10.2.128.240] INFO: Hashing 10.2.128.240[500] with algo #2 
2017-03-31 22:23:30: INFO: NAT-D payload #1 verified
2017-03-31 22:23:30: INFO: NAT detected: ME 
2017-03-31 22:23:30: [10.2.128.240] INFO: Hashing 10.2.128.240[500] with algo #2 
2017-03-31 22:23:30: [10.0.0.1] INFO: Hashing 10.0.0.1[500] with algo #2 
2017-03-31 22:23:30: INFO: Adding remote and local NAT-D payloads.
2017-03-31 22:23:30: INFO: NAT-T: ports changed to: 10.2.128.240[4500]<->10.0.0.1[4500]
2017-03-31 22:23:30: INFO: KA list add: 10.0.0.1[4500]->10.2.128.240[4500]
2017-03-31 22:23:47: [10.2.128.240] INFO: request for establishing IPsec-SA was queued due to no phase1 found.
2017-03-31 22:24:18: [10.2.128.240] ERROR: phase2 negotiation failed due to time up waiting for phase1. ESP 10.2.128.240[0]->10.0.0.1[0] 
2017-03-31 22:24:18: INFO: delete phase 2 handler.
2017-03-31 22:24:20: ERROR: phase1 negotiation failed due to time up. 219e887f75040cf2:bc128f909fd3792d
2017-03-31 22:24:20: INFO: KA remove: 10.0.0.1[4500]->10.2.128.240[4500]
2017-03-31 22:24:35: INFO: respond new phase 1 negotiation: 10.0.0.1[500]<=>10.2.128.240[500]
2017-03-31 22:24:35: INFO: begin Identity Protection mode.
2017-03-31 22:24:35: INFO: received Vendor ID: DPD
2017-03-31 22:24:35: INFO: received Vendor ID: FRAGMENTATION
2017-03-31 22:24:35: INFO: received Vendor ID: RFC 3947
2017-03-31 22:24:35: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-03
2017-03-31 22:24:35: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-02

2017-03-31 22:24:35: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-02
2017-03-31 22:24:35: [10.2.128.240] INFO: Selected NAT-T version: RFC 3947
2017-03-31 22:24:35: [10.0.0.1] INFO: Hashing 10.0.0.1[500] with algo #2 
2017-03-31 22:24:35: INFO: NAT-D payload #0 doesn't match
2017-03-31 22:24:35: [10.2.128.240] INFO: Hashing 10.2.128.240[500] with algo #2 
2017-03-31 22:24:35: INFO: NAT-D payload #1 verified
2017-03-31 22:24:35: INFO: NAT detected: ME 
2017-03-31 22:24:35: [10.2.128.240] INFO: Hashing 10.2.128.240[500] with algo #2 
2017-03-31 22:24:35: [10.0.0.1] INFO: Hashing 10.0.0.1[500] with algo #2 
2017-03-31 22:24:35: INFO: Adding remote and local NAT-D payloads.
2017-03-31 22:24:35: INFO: NAT-T: ports changed to: 10.2.128.240[4500]<->10.0.0.1[4500]
2017-03-31 22:24:35: INFO: KA list add: 10.0.0.1[4500]->10.2.128.240[4500]
2017-03-31 22:25:25: ERROR: phase1 negotiation failed due to time up. 4364ff89de32bb95:2ffe2d3373b58c40
2017-03-31 22:25:25: INFO: KA remove: 10.0.0.1[4500]->10.2.128.240[4500]
2017-03-31 22:25:30: INFO: respond new phase 1 negotiation: 10.0.0.1[500]<=>10.2.128.240[500]
2017-03-31 22:25:30: INFO: begin Identity Protection mode.
2017-03-31 22:25:30: INFO: received Vendor ID: DPD
2017-03-31 22:25:30: INFO: received Vendor ID: FRAGMENTATION
2017-03-31 22:25:30: INFO: received Vendor ID: RFC 3947
2017-03-31 22:25:30: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-03
2017-03-31 22:25:30: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-02

2017-03-31 22:25:30: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-02
2017-03-31 22:25:30: [10.2.128.240] INFO: Selected NAT-T version: RFC 3947
2017-03-31 22:25:30: [10.0.0.1] INFO: Hashing 10.0.0.1[500] with algo #2 
2017-03-31 22:25:30: INFO: NAT-D payload #0 doesn't match
2017-03-31 22:25:30: [10.2.128.240] INFO: Hashing 10.2.128.240[500] with algo #2 
2017-03-31 22:25:30: INFO: NAT-D payload #1 verified
2017-03-31 22:25:30: INFO: NAT detected: ME 
2017-03-31 22:25:30: [10.2.128.240] INFO: Hashing 10.2.128.240[500] with algo #2 
2017-03-31 22:25:30: [10.0.0.1] INFO: Hashing 10.0.0.1[500] with algo #2 
2017-03-31 22:25:30: INFO: Adding remote and local NAT-D payloads.
2017-03-31 22:25:30: INFO: NAT-T: ports changed to: 10.2.128.240[4500]<->10.0.0.1[4500]
2017-03-31 22:25:30: INFO: KA list add: 10.0.0.1[4500]->10.2.128.240[4500]
2017-03-31 22:27:14: INFO: @(#)ipsec-tools 0.8.1 (http://ipsec-tools.sourceforge.net)
2017-03-31 22:27:14: INFO: @(#)This product linked OpenSSL 1.0.1g 7 Apr 2014 (http://www.openssl.org/)
2017-03-31 22:27:14: INFO: Reading configuration from "/var/run/racoon.conf"
2017-03-31 22:27:14: DEBUG: call pfkey_send_register for AH
2017-03-31 22:27:14: DEBUG: call pfkey_send_register for ESP
2017-03-31 22:27:14: DEBUG: call pfkey_send_register for IPCOMP
2017-03-31 22:27:14: DEBUG: reading config file /var/run/racoon.conf
2017-03-31 22:27:14: DEBUG: no check of compression algorithm; not supported in sadb message.
2017-03-31 22:27:14: DEBUG: getsainfo params: loc='ANONYMOUS' rmt='ANONYMOUS' peer='NULL' client='NULL' id=0
2017-03-31 22:27:14: DEBUG: open /var/racoon/racoon.sock as racoon management.
2017-03-31 22:27:14: INFO: 10.0.0.1[4500] used for NAT-T
2017-03-31 22:27:14: INFO: 10.0.0.1[4500] used as isakmp port (fd=5)
2017-03-31 22:27:14: INFO: 10.0.0.1[500] used for NAT-T
2017-03-31 22:27:14: INFO: 10.0.0.1[500] used as isakmp port (fd=6)
2017-03-31 22:27:14: DEBUG: pk_recv: retry[0] recv() 
2017-03-31 22:27:14: DEBUG: got pfkey X_SPDDUMP message
2017-03-31 22:27:14: DEBUG: pk_recv: retry[0] recv() 
2017-03-31 22:27:14: DEBUG: got pfkey X_SPDDUMP message
2017-03-31 22:27:14: DEBUG: sub:0xbff827fc: 10.100.0.0/24[0] 10.100.1.0/24[0] proto=any dir=fwd
2017-03-31 22:27:14: DEBUG: db :0x8b98668: 10.100.1.0/24[0] 10.100.0.0/24[0] proto=any dir=out
2017-03-31 22:27:14: DEBUG: pk_recv: retry[0] recv() 
2017-03-31 22:27:14: DEBUG: got pfkey X_SPDDUMP message
2017-03-31 22:27:14: DEBUG: sub:0xbff827fc: 10.100.0.0/24[0] 10.100.1.0/24[0] proto=any dir=in
2017-03-31 22:27:14: DEBUG: db :0x8b98668: 10.100.1.0/24[0] 10.100.0.0/24[0] proto=any dir=out
2017-03-31 22:27:14: DEBUG: sub:0xbff827fc: 10.100.0.0/24[0] 10.100.1.0/24[0] proto=any dir=in
2017-03-31 22:27:14: DEBUG: db :0x8b988b8: 10.100.0.0/24[0] 10.100.1.0/24[0] proto=any dir=fwd
2017-03-31 22:27:14: DEBUG: pk_recv: retry[0] recv() 
2017-03-31 22:27:14: DEBUG: got pfkey X_SPDDUMP message
2017-03-31 22:27:14: DEBUG: sub:0xbff827fc: 10.0.0.1/32[0] 0.0.0.0/0[0] proto=any dir=out
2017-03-31 22:27:14: DEBUG: db :0x8b98668: 10.100.1.0/24[0] 10.100.0.0/24[0] proto=any dir=out
2017-03-31 22:27:14: DEBUG: sub:0xbff827fc: 10.0.0.1/32[0] 0.0.0.0/0[0] proto=any dir=out
2017-03-31 22:27:14: DEBUG: db :0x8b988b8: 10.100.0.0/24[0] 10.100.1.0/24[0] proto=any dir=fwd
2017-03-31 22:27:14: DEBUG: sub:0xbff827fc: 10.0.0.1/32[0] 0.0.0.0/0[0] proto=any dir=out
2017-03-31 22:27:14: DEBUG: db :0x8b98b08: 10.100.0.0/24[0] 10.100.1.0/24[0] proto=any dir=in
2017-03-31 22:27:14: DEBUG: pk_recv: retry[0] recv() 
2017-03-31 22:27:14: DEBUG: got pfkey X_SPDDUMP message
2017-03-31 22:27:14: DEBUG: sub:0xbff827fc: 0.0.0.0/0[0] 10.0.0.1/32[0] proto=any dir=fwd
2017-03-31 22:27:14: DEBUG: db :0x8b98668: 10.100.1.0/24[0] 10.100.0.0/24[0] proto=any dir=out
2017-03-31 22:27:14: DEBUG: sub:0xbff827fc: 0.0.0.0/0[0] 10.0.0.1/32[0] proto=any dir=fwd
2017-03-31 22:27:14: DEBUG: db :0x8b988b8: 10.100.0.0/24[0] 10.100.1.0/24[0] proto=any dir=fwd
2017-03-31 22:27:14: DEBUG: sub:0xbff827fc: 0.0.0.0/0[0] 10.0.0.1/32[0] proto=any dir=fwd
2017-03-31 22:27:14: DEBUG: db :0x8b98b08: 10.100.0.0/24[0] 10.100.1.0/24[0] proto=any dir=in
2017-03-31 22:27:14: DEBUG: sub:0xbff827fc: 0.0.0.0/0[0] 10.0.0.1/32[0] proto=any dir=fwd
2017-03-31 22:27:14: DEBUG: db :0x8b98d58: 10.0.0.1/32[0] 0.0.0.0/0[0] proto=any dir=out
2017-03-31 22:27:14: DEBUG: pk_recv: retry[0] recv() 
2017-03-31 22:27:14: DEBUG: got pfkey X_SPDDUMP message
2017-03-31 22:27:14: DEBUG: sub:0xbff827fc: 0.0.0.0/0[0] 10.0.0.1/32[0] proto=any dir=in
2017-03-31 22:27:14: DEBUG: db :0x8b98668: 10.100.1.0/24[0] 10.100.0.0/24[0] proto=any dir=out
2017-03-31 22:27:14: DEBUG: sub:0xbff827fc: 0.0.0.0/0[0] 10.0.0.1/32[0] proto=any dir=in
2017-03-31 22:27:14: DEBUG: db :0x8b988b8: 10.100.0.0/24[0] 10.100.1.0/24[0] proto=any dir=fwd
2017-03-31 22:27:14: DEBUG: sub:0xbff827fc: 0.0.0.0/0[0] 10.0.0.1/32[0] proto=any dir=in
2017-03-31 22:27:14: DEBUG: db :0x8b98b08: 10.100.0.0/24[0] 10.100.1.0/24[0] proto=any dir=in
2017-03-31 22:27:14: DEBUG: sub:0xbff827fc: 0.0.0.0/0[0] 10.0.0.1/32[0] proto=any dir=in
2017-03-31 22:27:14: DEBUG: db :0x8b98d58: 10.0.0.1/32[0] 0.0.0.0/0[0] proto=any dir=out
2017-03-31 22:27:14: DEBUG: sub:0xbff827fc: 0.0.0.0/0[0] 10.0.0.1/32[0] proto=any dir=in
2017-03-31 22:27:14: DEBUG: db :0x8b98e90: 0.0.0.0/0[0] 10.0.0.1/32[0] proto=any dir=fwd
2017-03-31 22:27:15: DEBUG: ===
2017-03-31 22:27:15: DEBUG: 68 bytes message received from 10.2.128.240[4500] to 10.0.0.1[4500]
2017-03-31 22:27:15: DEBUG: 
ed079203 5c5a06b6 d4208d38 c1861a8d 05100201 00000000 00000044 f8d493ab
57bf19fb f971ba3a a39fde89 0f7637a3 9cef19e9 04f3cf21 daef6bde b8bbddab
14438fc6
2017-03-31 22:27:15: [10.2.128.240] DEBUG: malformed cookie received or the spi expired.
2017-03-31 22:27:30: DEBUG: ===
2017-03-31 22:27:30: DEBUG: 200 bytes message received from 10.2.128.240[500] to 10.0.0.1[500]
2017-03-31 22:27:30: DEBUG: 
8c6688ca baaf90ca 00000000 00000000 01100200 00000000 000000c8 0d000034
00000001 00000001 00000028 00010001 00000020 00010000 800b0001 800c7080
80010005 80020002 80030001 80040002 0d000014 afcad713 68a1f1c9 6b8696fc
77570100 0d000014 4048b7d5 6ebce885 25e7de7f 00d6c2d3 0d000014 4a131c81
07035845 5c5728f2 0e95452f 0d000014 7d9419a6 5310ca6f 2c179d92 15529d56
0d000014 90cb8091 3ebb696e 086381b5 ec427b1f 00000014 cd604643 35df21f8
7cfdb2fc 68b6a448
2017-03-31 22:27:30: DEBUG: ===
2017-03-31 22:27:30: INFO: respond new phase 1 negotiation: 10.0.0.1[500]<=>10.2.128.240[500]
2017-03-31 22:27:30: INFO: begin Identity Protection mode.
2017-03-31 22:27:30: DEBUG: begin.
2017-03-31 22:27:30: DEBUG: seen nptype=1(sa)
2017-03-31 22:27:30: DEBUG: seen nptype=13(vid)
2017-03-31 22:27:30: DEBUG: seen nptype=13(vid)
2017-03-31 22:27:30: DEBUG: seen nptype=13(vid)
2017-03-31 22:27:30: DEBUG: seen nptype=13(vid)
2017-03-31 22:27:30: DEBUG: seen nptype=13(vid)
2017-03-31 22:27:30: DEBUG: seen nptype=13(vid)
2017-03-31 22:27:30: DEBUG: succeed.
2017-03-31 22:27:30: INFO: received Vendor ID: DPD
2017-03-31 22:27:30: DEBUG: remote supports DPD
2017-03-31 22:27:30: INFO: received Vendor ID: FRAGMENTATION
2017-03-31 22:27:30: INFO: received Vendor ID: RFC 3947
2017-03-31 22:27:30: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-03
2017-03-31 22:27:30: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-02

2017-03-31 22:27:30: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-02
2017-03-31 22:27:30: [10.2.128.240] INFO: Selected NAT-T version: RFC 3947
2017-03-31 22:27:30: DEBUG: total SA len=48
2017-03-31 22:27:30: DEBUG: 
00000001 00000001 00000028 00010001 00000020 00010000 800b0001 800c7080
80010005 80020002 80030001 80040002
2017-03-31 22:27:30: DEBUG: begin.
2017-03-31 22:27:30: DEBUG: seen nptype=2(prop)
2017-03-31 22:27:30: DEBUG: succeed.
2017-03-31 22:27:30: DEBUG: proposal #0 len=40
2017-03-31 22:27:30: DEBUG: begin.
2017-03-31 22:27:30: DEBUG: seen nptype=3(trns)
2017-03-31 22:27:30: DEBUG: succeed.
2017-03-31 22:27:30: DEBUG: transform #0 len=32
2017-03-31 22:27:30: DEBUG: type=Life Type, flag=0x8000, lorv=seconds
2017-03-31 22:27:30: DEBUG: type=Life Duration, flag=0x8000, lorv=28800
2017-03-31 22:27:30: DEBUG: type=Encryption Algorithm, flag=0x8000, lorv=3DES-CBC
2017-03-31 22:27:30: DEBUG: encryption(3des)
2017-03-31 22:27:30: DEBUG: type=Hash Algorithm, flag=0x8000, lorv=SHA
2017-03-31 22:27:30: DEBUG: hash(sha1)
2017-03-31 22:27:30: DEBUG: type=Authentication Method, flag=0x8000, lorv=pre-shared key
2017-03-31 22:27:30: DEBUG: type=Group Description, flag=0x8000, lorv=1024-bit MODP group
2017-03-31 22:27:30: DEBUG: hmac(modp1024)
2017-03-31 22:27:30: DEBUG: pair 0:
2017-03-31 22:27:30: DEBUG:  0x8b975a0: next=(nil) tnext=(nil)
2017-03-31 22:27:30: DEBUG: proposal #0: 1 transform
2017-03-31 22:27:30: DEBUG: type=Life Type, flag=0x8000, lorv=seconds
2017-03-31 22:27:30: DEBUG: type=Life Duration, flag=0x8000, lorv=28800
2017-03-31 22:27:30: DEBUG: type=Encryption Algorithm, flag=0x8000, lorv=3DES-CBC
2017-03-31 22:27:30: DEBUG: type=Hash Algorithm, flag=0x8000, lorv=SHA
2017-03-31 22:27:30: DEBUG: type=Authentication Method, flag=0x8000, lorv=pre-shared key
2017-03-31 22:27:30: DEBUG: type=Group Description, flag=0x8000, lorv=1024-bit MODP group
2017-03-31 22:27:30: DEBUG: prop#=0, prot-id=ISAKMP, spi-size=0, #trns=1
2017-03-31 22:27:30: DEBUG: trns#=0, trns-id=IKE
2017-03-31 22:27:30: DEBUG:   lifetime = 28800
2017-03-31 22:27:30: DEBUG:   lifebyte = 0
2017-03-31 22:27:30: DEBUG:   enctype = 3DES-CBC
2017-03-31 22:27:30: DEBUG:   encklen = 0
2017-03-31 22:27:30: DEBUG:   hashtype = SHA
2017-03-31 22:27:30: DEBUG:   authmethod = pre-shared key
2017-03-31 22:27:30: DEBUG:   dh_group = 1024-bit MODP group
2017-03-31 22:27:30: DEBUG: an acceptable proposal found.
2017-03-31 22:27:30: DEBUG: hmac(modp1024)
2017-03-31 22:27:30: DEBUG: agreed on pre-shared key auth.
2017-03-31 22:27:30: DEBUG: ===
2017-03-31 22:27:30: DEBUG: new cookie:
a8d8758b59948609 
2017-03-31 22:27:30: DEBUG: add payload of len 48, next type 13
2017-03-31 22:27:30: DEBUG: add payload of len 16, next type 13
2017-03-31 22:27:30: DEBUG: add payload of len 16, next type 0
2017-03-31 22:27:30: DEBUG: 120 bytes from 10.0.0.1[500] to 10.2.128.240[500]
2017-03-31 22:27:30: DEBUG: sockname 10.0.0.1[500]
2017-03-31 22:27:30: DEBUG: send packet from 10.0.0.1[500]
2017-03-31 22:27:30: DEBUG: send packet to 10.2.128.240[500]
2017-03-31 22:27:30: DEBUG: src4 10.0.0.1[500]
2017-03-31 22:27:30: DEBUG: dst4 10.2.128.240[500]
2017-03-31 22:27:30: DEBUG: 1 times of 120 bytes message will be sent to 10.2.128.240[500]
2017-03-31 22:27:30: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 01100200 00000000 00000078 0d000034
00000001 00000001 00000028 00010001 00000020 00010000 800b0001 800c7080
80010005 80020002 80030001 80040002 0d000014 4a131c81 07035845 5c5728f2
0e95452f 00000014 afcad713 68a1f1c9 6b8696fc 77570100
2017-03-31 22:27:30: DEBUG: resend phase1 packet 8c6688cabaaf90ca:a8d8758b59948609
2017-03-31 22:27:30: DEBUG: ===
2017-03-31 22:27:30: DEBUG: 244 bytes message received from 10.2.128.240[500] to 10.0.0.1[500]
2017-03-31 22:27:30: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 04100200 00000000 000000f4 0a000084
7ad8aaae 4458f798 8e88b6ce 1c6faa4a 0aeba82e 9253d5e9 247e0ad2 179ecceb
94d3c134 b39d2334 23d5cebc 9388e0dc 30a7292a 5e290cdd 21ebd106 47e85981
0ea13913 b31ae084 69e45313 3b1079b5 df652557 299701b1 26629dcb 2cb00ffc
646e3162 99391cc3 651ac57f 50cd5ce7 3cd9be3d 3f763e55 f2f5f330 33438965
14000024 fe6867a1 cb0f44f3 7851c710 a2bcd66b 1cba466d 5e8c92be eb4c87e4
0bcea355 14000018 55ac5869 f29600c7 862e8355 ca8f1ea4 c6ea5267 00000018
460c94de 5fc70b50 76215b0c 922352a2 676154b2
2017-03-31 22:27:30: DEBUG: begin.
2017-03-31 22:27:30: DEBUG: seen nptype=4(ke)
2017-03-31 22:27:30: DEBUG: seen nptype=10(nonce)
2017-03-31 22:27:30: DEBUG: seen nptype=20(nat-d)
2017-03-31 22:27:30: DEBUG: seen nptype=20(nat-d)
2017-03-31 22:27:30: DEBUG: succeed.
2017-03-31 22:27:30: [10.0.0.1] INFO: Hashing 10.0.0.1[500] with algo #2 
2017-03-31 22:27:30: DEBUG: hash(sha1)
2017-03-31 22:27:30: INFO: NAT-D payload #0 doesn't match
2017-03-31 22:27:30: [10.2.128.240] INFO: Hashing 10.2.128.240[500] with algo #2 
2017-03-31 22:27:30: DEBUG: hash(sha1)
2017-03-31 22:27:30: INFO: NAT-D payload #1 verified
2017-03-31 22:27:30: INFO: NAT detected: ME 
2017-03-31 22:27:30: DEBUG: ===
2017-03-31 22:27:31: DEBUG: compute DH's private.
2017-03-31 22:27:31: DEBUG: 
4a61f8ff c94a1a28 37d9b62a 24620bb9 0b7db18e 2d451775 fb9f3ba5 5fc8aaa1
214199d8 80590545 7c02cd8f 147a959b 86ee2f35 00f89e53 71e1af51 72611a8a
4ae1d84b f21cf709 07eb2492 f5d6852f b2801f5f 08066634 fb580617 c33cfbcc
de4b957a 77364a5e d239d81f 8aae16a1 8774b84f fb5ba068 6aadb214 5ac49cdd
2017-03-31 22:27:31: DEBUG: compute DH's public.
2017-03-31 22:27:31: DEBUG: 
7976a87d 8089219d 352ffa4d d69f70c1 0ec0f3f7 a5d414d1 1fb64759 a0ab2ae7
863da397 187568b6 8f96c008 9318cd96 717a19ad 762c68f9 dedd3956 1272f2ba
a5730437 ca99dcb5 70ea58f3 f2fde99f 842c3be2 d72ae8ec 00554f9f 1b4906c1
6ed7aa45 d2a97d0b 63edba3f eab19603 8ba11b33 5e7b3877 aedb290d 1e74a18f
2017-03-31 22:27:31: [10.2.128.240] INFO: Hashing 10.2.128.240[500] with algo #2 
2017-03-31 22:27:31: DEBUG: hash(sha1)
2017-03-31 22:27:31: [10.0.0.1] INFO: Hashing 10.0.0.1[500] with algo #2 
2017-03-31 22:27:31: DEBUG: hash(sha1)
2017-03-31 22:27:31: INFO: Adding remote and local NAT-D payloads.
2017-03-31 22:27:31: DEBUG: add payload of len 128, next type 10
2017-03-31 22:27:31: DEBUG: add payload of len 16, next type 20
2017-03-31 22:27:31: DEBUG: add payload of len 20, next type 20
2017-03-31 22:27:31: DEBUG: add payload of len 20, next type 0
2017-03-31 22:27:31: DEBUG: 228 bytes from 10.0.0.1[500] to 10.2.128.240[500]
2017-03-31 22:27:31: DEBUG: sockname 10.0.0.1[500]
2017-03-31 22:27:31: DEBUG: send packet from 10.0.0.1[500]
2017-03-31 22:27:31: DEBUG: send packet to 10.2.128.240[500]
2017-03-31 22:27:31: DEBUG: src4 10.0.0.1[500]
2017-03-31 22:27:31: DEBUG: dst4 10.2.128.240[500]
2017-03-31 22:27:31: DEBUG: 1 times of 228 bytes message will be sent to 10.2.128.240[500]
2017-03-31 22:27:31: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 04100200 00000000 000000e4 0a000084
7976a87d 8089219d 352ffa4d d69f70c1 0ec0f3f7 a5d414d1 1fb64759 a0ab2ae7
863da397 187568b6 8f96c008 9318cd96 717a19ad 762c68f9 dedd3956 1272f2ba
a5730437 ca99dcb5 70ea58f3 f2fde99f 842c3be2 d72ae8ec 00554f9f 1b4906c1
6ed7aa45 d2a97d0b 63edba3f eab19603 8ba11b33 5e7b3877 aedb290d 1e74a18f
14000014 ac2c6815 c7c9aeb4 ce8ec064 a6f9f6ae 14000018 460c94de 5fc70b50
76215b0c 922352a2 676154b2 00000018 726781ed 383ec15b 882948ce f0312d37
33ae662d
2017-03-31 22:27:31: DEBUG: resend phase1 packet 8c6688cabaaf90ca:a8d8758b59948609
2017-03-31 22:27:31: DEBUG: compute DH's shared.
2017-03-31 22:27:31: DEBUG: 
cedf74e0 ee937e71 e3b06e95 538b3499 7fa8a52e 9c141b18 34eb1952 f6b15fd2
91f8acbe 2ac97064 6a26570f 7b1387c1 73947dd4 843b38c8 4ac570d3 71bcd3cc
92446ec0 9a64f484 19779a82 a9bd0158 419bed6b e93507fd a922f885 0a3fa93b
f5f2e54d fd0ba31f 4062c22a e544beaf 65740a2f 47eb098c 1e7e2a7d e58f2214
2017-03-31 22:27:31: DEBUG: the psk found.
2017-03-31 22:27:31: DEBUG: nonce 1: 2017-03-31 22:27:31: DEBUG: 
fe6867a1 cb0f44f3 7851c710 a2bcd66b 1cba466d 5e8c92be eb4c87e4 0bcea355
2017-03-31 22:27:31: DEBUG: nonce 2: 2017-03-31 22:27:31: DEBUG: 
ac2c6815 c7c9aeb4 ce8ec064 a6f9f6ae
2017-03-31 22:27:31: DEBUG: hmac(hmac_sha1)
2017-03-31 22:27:31: DEBUG: SKEYID computed:
2017-03-31 22:27:31: DEBUG: 
b1656f06 ea90927c 4803af17 74f9587f b8b21953
2017-03-31 22:27:31: DEBUG: hmac(hmac_sha1)
2017-03-31 22:27:31: DEBUG: SKEYID_d computed:
2017-03-31 22:27:31: DEBUG: 
be2a4a6a 89287d5d e5d5018f 62a2a0e7 b6166599
2017-03-31 22:27:31: DEBUG: hmac(hmac_sha1)
2017-03-31 22:27:31: DEBUG: SKEYID_a computed:
2017-03-31 22:27:31: DEBUG: 
a68409a7 db93f039 3d4b639c 6e85eae6 0f239b37
2017-03-31 22:27:31: DEBUG: hmac(hmac_sha1)
2017-03-31 22:27:31: DEBUG: SKEYID_e computed:
2017-03-31 22:27:31: DEBUG: 
cdbb51d8 7528928f 62ba3368 05fed739 32d0456f
2017-03-31 22:27:31: DEBUG: encryption(3des)
2017-03-31 22:27:31: DEBUG: hash(sha1)
2017-03-31 22:27:31: DEBUG: len(SKEYID_e) < len(Ka) (20 < 24), generating long key (Ka = K1 | K2 | ...)
2017-03-31 22:27:31: DEBUG: hmac(hmac_sha1)
2017-03-31 22:27:31: DEBUG: compute intermediate encryption key K1
2017-03-31 22:27:31: DEBUG: 
00
2017-03-31 22:27:31: DEBUG: 
ef0edddf d49becb1 d059bfb2 c01479f5 8bf1e315
2017-03-31 22:27:31: DEBUG: hmac(hmac_sha1)
2017-03-31 22:27:31: DEBUG: compute intermediate encryption key K2
2017-03-31 22:27:31: DEBUG: 
ef0edddf d49becb1 d059bfb2 c01479f5 8bf1e315
2017-03-31 22:27:31: DEBUG: 
a5456312 17c84b4d f2442aeb 2326f84d f581adc6
2017-03-31 22:27:31: DEBUG: final encryption key computed:
2017-03-31 22:27:31: DEBUG: 
ef0edddf d49becb1 d059bfb2 c01479f5 8bf1e315 a5456312
2017-03-31 22:27:31: DEBUG: hash(sha1)
2017-03-31 22:27:31: DEBUG: encryption(3des)
2017-03-31 22:27:31: DEBUG: IV computed:
2017-03-31 22:27:31: DEBUG: 
12b39be5 538407a7
2017-03-31 22:27:31: DEBUG: ===
2017-03-31 22:27:31: DEBUG: 68 bytes message received from 10.2.128.240[4500] to 10.0.0.1[4500]
2017-03-31 22:27:31: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 05100201 00000000 00000044 ed0655f5
0f6c36ad 91a2c8b4 8cbc402c 55873cd1 828a756d 309ecc8e 8e2f68b1 597b1684
a3ad0453
2017-03-31 22:27:31: INFO: NAT-T: ports changed to: 10.2.128.240[4500]<->10.0.0.1[4500]
2017-03-31 22:27:31: INFO: KA list add: 10.0.0.1[4500]->10.2.128.240[4500]
2017-03-31 22:27:31: DEBUG: begin decryption.
2017-03-31 22:27:31: DEBUG: encryption(3des)
2017-03-31 22:27:31: DEBUG: IV was saved for next processing:
2017-03-31 22:27:31: DEBUG: 
597b1684 a3ad0453
2017-03-31 22:27:31: DEBUG: encryption(3des)
2017-03-31 22:27:31: DEBUG: with key:
2017-03-31 22:27:31: DEBUG: 
ef0edddf d49becb1 d059bfb2 c01479f5 8bf1e315 a5456312
2017-03-31 22:27:31: DEBUG: decrypted payload by IV:
2017-03-31 22:27:31: DEBUG: 
12b39be5 538407a7
2017-03-31 22:27:31: DEBUG: decrypted payload, but not trimed.
2017-03-31 22:27:31: DEBUG: 
db504ea4 e924a3bf 14bfcb3c 9a5f972c 778e7c23 3199be4d 59517584 1178312e
cd29c3c7 bb1f581d
2017-03-31 22:27:31: DEBUG: padding len=30
2017-03-31 22:27:31: DEBUG: skip to trim padding.
2017-03-31 22:27:31: DEBUG: decrypted.
2017-03-31 22:27:31: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 05100201 00000000 00000044 db504ea4
e924a3bf 14bfcb3c 9a5f972c 778e7c23 3199be4d 59517584 1178312e cd29c3c7
bb1f581d
2017-03-31 22:27:31: DEBUG: begin.
2017-03-31 22:27:31: DEBUG: seen nptype=5(id)
2017-03-31 22:27:31: DEBUG: invalid length of payload
2017-03-31 22:27:31: DEBUG: ===
2017-03-31 22:27:31: DEBUG: 68 bytes message received from 10.2.128.240[4500] to 10.0.0.1[4500]
2017-03-31 22:27:31: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 05100201 00000000 00000044 ed0655f5
0f6c36ad 91a2c8b4 8cbc402c 55873cd1 828a756d 309ecc8e 8e2f68b1 597b1684
a3ad0453
2017-03-31 22:27:31: DEBUG: begin decryption.
2017-03-31 22:27:31: DEBUG: encryption(3des)
2017-03-31 22:27:31: DEBUG: IV was saved for next processing:
2017-03-31 22:27:31: DEBUG: 
597b1684 a3ad0453
2017-03-31 22:27:31: DEBUG: encryption(3des)
2017-03-31 22:27:31: DEBUG: with key:
2017-03-31 22:27:31: DEBUG: 
ef0edddf d49becb1 d059bfb2 c01479f5 8bf1e315 a5456312
2017-03-31 22:27:31: DEBUG: decrypted payload by IV:
2017-03-31 22:27:31: DEBUG: 
12b39be5 538407a7
2017-03-31 22:27:31: DEBUG: decrypted payload, but not trimed.
2017-03-31 22:27:31: DEBUG: 
db504ea4 e924a3bf 14bfcb3c 9a5f972c 778e7c23 3199be4d 59517584 1178312e
cd29c3c7 bb1f581d
2017-03-31 22:27:31: DEBUG: padding len=30
2017-03-31 22:27:31: DEBUG: skip to trim padding.
2017-03-31 22:27:31: DEBUG: decrypted.
2017-03-31 22:27:31: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 05100201 00000000 00000044 db504ea4
e924a3bf 14bfcb3c 9a5f972c 778e7c23 3199be4d 59517584 1178312e cd29c3c7
bb1f581d
2017-03-31 22:27:31: DEBUG: begin.
2017-03-31 22:27:31: DEBUG: seen nptype=5(id)
2017-03-31 22:27:31: DEBUG: invalid length of payload
2017-03-31 22:27:32: DEBUG: ===
2017-03-31 22:27:32: DEBUG: 68 bytes message received from 10.2.128.240[4500] to 10.0.0.1[4500]
2017-03-31 22:27:32: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 05100201 00000000 00000044 ed0655f5
0f6c36ad 91a2c8b4 8cbc402c 55873cd1 828a756d 309ecc8e 8e2f68b1 597b1684
a3ad0453
2017-03-31 22:27:32: DEBUG: begin decryption.
2017-03-31 22:27:32: DEBUG: encryption(3des)
2017-03-31 22:27:32: DEBUG: IV was saved for next processing:
2017-03-31 22:27:32: DEBUG: 
597b1684 a3ad0453
2017-03-31 22:27:32: DEBUG: encryption(3des)
2017-03-31 22:27:32: DEBUG: with key:
2017-03-31 22:27:32: DEBUG: 
ef0edddf d49becb1 d059bfb2 c01479f5 8bf1e315 a5456312
2017-03-31 22:27:32: DEBUG: decrypted payload by IV:
2017-03-31 22:27:32: DEBUG: 
12b39be5 538407a7
2017-03-31 22:27:32: DEBUG: decrypted payload, but not trimed.
2017-03-31 22:27:32: DEBUG: 
db504ea4 e924a3bf 14bfcb3c 9a5f972c 778e7c23 3199be4d 59517584 1178312e
cd29c3c7 bb1f581d
2017-03-31 22:27:32: DEBUG: padding len=30
2017-03-31 22:27:32: DEBUG: skip to trim padding.
2017-03-31 22:27:32: DEBUG: decrypted.
2017-03-31 22:27:32: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 05100201 00000000 00000044 db504ea4
e924a3bf 14bfcb3c 9a5f972c 778e7c23 3199be4d 59517584 1178312e cd29c3c7
bb1f581d
2017-03-31 22:27:32: DEBUG: begin.
2017-03-31 22:27:32: DEBUG: seen nptype=5(id)
2017-03-31 22:27:32: DEBUG: invalid length of payload
2017-03-31 22:27:33: DEBUG: ===
2017-03-31 22:27:33: DEBUG: 68 bytes message received from 10.2.128.240[4500] to 10.0.0.1[4500]
2017-03-31 22:27:33: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 05100201 00000000 00000044 ed0655f5
0f6c36ad 91a2c8b4 8cbc402c 55873cd1 828a756d 309ecc8e 8e2f68b1 597b1684
a3ad0453
2017-03-31 22:27:33: DEBUG: begin decryption.
2017-03-31 22:27:33: DEBUG: encryption(3des)
2017-03-31 22:27:33: DEBUG: IV was saved for next processing:
2017-03-31 22:27:33: DEBUG: 
597b1684 a3ad0453
2017-03-31 22:27:33: DEBUG: encryption(3des)
2017-03-31 22:27:33: DEBUG: with key:
2017-03-31 22:27:33: DEBUG: 
ef0edddf d49becb1 d059bfb2 c01479f5 8bf1e315 a5456312
2017-03-31 22:27:33: DEBUG: decrypted payload by IV:
2017-03-31 22:27:33: DEBUG: 
12b39be5 538407a7
2017-03-31 22:27:33: DEBUG: decrypted payload, but not trimed.
2017-03-31 22:27:33: DEBUG: 
db504ea4 e924a3bf 14bfcb3c 9a5f972c 778e7c23 3199be4d 59517584 1178312e
cd29c3c7 bb1f581d
2017-03-31 22:27:33: DEBUG: padding len=30
2017-03-31 22:27:33: DEBUG: skip to trim padding.
2017-03-31 22:27:33: DEBUG: decrypted.
2017-03-31 22:27:33: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 05100201 00000000 00000044 db504ea4
e924a3bf 14bfcb3c 9a5f972c 778e7c23 3199be4d 59517584 1178312e cd29c3c7
bb1f581d
2017-03-31 22:27:33: DEBUG: begin.
2017-03-31 22:27:33: DEBUG: seen nptype=5(id)
2017-03-31 22:27:33: DEBUG: invalid length of payload
2017-03-31 22:27:34: DEBUG: KA: 10.0.0.1[4500]->10.2.128.240[4500]
2017-03-31 22:27:34: DEBUG: sockname 10.0.0.1[4500]
2017-03-31 22:27:34: DEBUG: send packet from 10.0.0.1[4500]
2017-03-31 22:27:34: DEBUG: send packet to 10.2.128.240[4500]
2017-03-31 22:27:34: DEBUG: src4 10.0.0.1[4500]
2017-03-31 22:27:34: DEBUG: dst4 10.2.128.240[4500]
2017-03-31 22:27:34: DEBUG: 1 times of 1 bytes message will be sent to 10.2.128.240[4500]
2017-03-31 22:27:34: DEBUG: 
ff
2017-03-31 22:27:35: DEBUG: ===
2017-03-31 22:27:35: DEBUG: 68 bytes message received from 10.2.128.240[4500] to 10.0.0.1[4500]
2017-03-31 22:27:35: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 05100201 00000000 00000044 ed0655f5
0f6c36ad 91a2c8b4 8cbc402c 55873cd1 828a756d 309ecc8e 8e2f68b1 597b1684
a3ad0453
2017-03-31 22:27:35: DEBUG: begin decryption.
2017-03-31 22:27:35: DEBUG: encryption(3des)
2017-03-31 22:27:35: DEBUG: IV was saved for next processing:
2017-03-31 22:27:35: DEBUG: 
597b1684 a3ad0453
2017-03-31 22:27:35: DEBUG: encryption(3des)
2017-03-31 22:27:35: DEBUG: with key:
2017-03-31 22:27:35: DEBUG: 
ef0edddf d49becb1 d059bfb2 c01479f5 8bf1e315 a5456312
2017-03-31 22:27:35: DEBUG: decrypted payload by IV:
2017-03-31 22:27:35: DEBUG: 
12b39be5 538407a7
2017-03-31 22:27:35: DEBUG: decrypted payload, but not trimed.
2017-03-31 22:27:35: DEBUG: 
db504ea4 e924a3bf 14bfcb3c 9a5f972c 778e7c23 3199be4d 59517584 1178312e
cd29c3c7 bb1f581d
2017-03-31 22:27:35: DEBUG: padding len=30
2017-03-31 22:27:35: DEBUG: skip to trim padding.
2017-03-31 22:27:35: DEBUG: decrypted.
2017-03-31 22:27:35: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 05100201 00000000 00000044 db504ea4
e924a3bf 14bfcb3c 9a5f972c 778e7c23 3199be4d 59517584 1178312e cd29c3c7
bb1f581d
2017-03-31 22:27:35: DEBUG: begin.
2017-03-31 22:27:35: DEBUG: seen nptype=5(id)
2017-03-31 22:27:35: DEBUG: invalid length of payload
2017-03-31 22:27:39: DEBUG: ===
2017-03-31 22:27:39: DEBUG: 68 bytes message received from 10.2.128.240[4500] to 10.0.0.1[4500]
2017-03-31 22:27:39: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 05100201 00000000 00000044 ed0655f5
0f6c36ad 91a2c8b4 8cbc402c 55873cd1 828a756d 309ecc8e 8e2f68b1 597b1684
a3ad0453
2017-03-31 22:27:39: DEBUG: begin decryption.
2017-03-31 22:27:39: DEBUG: encryption(3des)
2017-03-31 22:27:39: DEBUG: IV was saved for next processing:
2017-03-31 22:27:39: DEBUG: 
597b1684 a3ad0453
2017-03-31 22:27:39: DEBUG: encryption(3des)
2017-03-31 22:27:39: DEBUG: with key:
2017-03-31 22:27:39: DEBUG: 
ef0edddf d49becb1 d059bfb2 c01479f5 8bf1e315 a5456312
2017-03-31 22:27:39: DEBUG: decrypted payload by IV:
2017-03-31 22:27:39: DEBUG: 
12b39be5 538407a7
2017-03-31 22:27:39: DEBUG: decrypted payload, but not trimed.
2017-03-31 22:27:39: DEBUG: 
db504ea4 e924a3bf 14bfcb3c 9a5f972c 778e7c23 3199be4d 59517584 1178312e
cd29c3c7 bb1f581d
2017-03-31 22:27:39: DEBUG: padding len=30
2017-03-31 22:27:39: DEBUG: skip to trim padding.
2017-03-31 22:27:39: DEBUG: decrypted.
2017-03-31 22:27:39: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 05100201 00000000 00000044 db504ea4
e924a3bf 14bfcb3c 9a5f972c 778e7c23 3199be4d 59517584 1178312e cd29c3c7
bb1f581d
2017-03-31 22:27:39: DEBUG: begin.
2017-03-31 22:27:39: DEBUG: seen nptype=5(id)
2017-03-31 22:27:39: DEBUG: invalid length of payload
2017-03-31 22:27:41: DEBUG: Adding NON-ESP marker
2017-03-31 22:27:41: DEBUG: 232 bytes from 10.0.0.1[4500] to 10.2.128.240[4500]
2017-03-31 22:27:41: DEBUG: sockname 10.0.0.1[4500]
2017-03-31 22:27:41: DEBUG: send packet from 10.0.0.1[4500]
2017-03-31 22:27:41: DEBUG: send packet to 10.2.128.240[4500]
2017-03-31 22:27:41: DEBUG: src4 10.0.0.1[4500]
2017-03-31 22:27:41: DEBUG: dst4 10.2.128.240[4500]
2017-03-31 22:27:41: DEBUG: 1 times of 232 bytes message will be sent to 10.2.128.240[4500]
2017-03-31 22:27:41: DEBUG: 
00000000 8c6688ca baaf90ca a8d8758b 59948609 04100200 00000000 000000e4
0a000084 7976a87d 8089219d 352ffa4d d69f70c1 0ec0f3f7 a5d414d1 1fb64759
a0ab2ae7 863da397 187568b6 8f96c008 9318cd96 717a19ad 762c68f9 dedd3956
1272f2ba a5730437 ca99dcb5 70ea58f3 f2fde99f 842c3be2 d72ae8ec 00554f9f
1b4906c1 6ed7aa45 d2a97d0b 63edba3f eab19603 8ba11b33 5e7b3877 aedb290d
1e74a18f 14000014 ac2c6815 c7c9aeb4 ce8ec064 a6f9f6ae 14000018 460c94de
5fc70b50 76215b0c 922352a2 676154b2 00000018 726781ed 383ec15b 882948ce
f0312d37 33ae662d
2017-03-31 22:27:41: DEBUG: resend phase1 packet 8c6688cabaaf90ca:a8d8758b59948609
2017-03-31 22:27:47: DEBUG: ===
2017-03-31 22:27:47: DEBUG: 68 bytes message received from 10.2.128.240[4500] to 10.0.0.1[4500]
2017-03-31 22:27:47: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 05100201 00000000 00000044 ed0655f5
0f6c36ad 91a2c8b4 8cbc402c 55873cd1 828a756d 309ecc8e 8e2f68b1 597b1684
a3ad0453
2017-03-31 22:27:47: DEBUG: begin decryption.
2017-03-31 22:27:47: DEBUG: encryption(3des)
2017-03-31 22:27:47: DEBUG: IV was saved for next processing:
2017-03-31 22:27:47: DEBUG: 
597b1684 a3ad0453
2017-03-31 22:27:47: DEBUG: encryption(3des)
2017-03-31 22:27:47: DEBUG: with key:
2017-03-31 22:27:47: DEBUG: 
ef0edddf d49becb1 d059bfb2 c01479f5 8bf1e315 a5456312
2017-03-31 22:27:47: DEBUG: decrypted payload by IV:
2017-03-31 22:27:47: DEBUG: 
12b39be5 538407a7
2017-03-31 22:27:47: DEBUG: decrypted payload, but not trimed.
2017-03-31 22:27:47: DEBUG: 
db504ea4 e924a3bf 14bfcb3c 9a5f972c 778e7c23 3199be4d 59517584 1178312e
cd29c3c7 bb1f581d
2017-03-31 22:27:47: DEBUG: padding len=30
2017-03-31 22:27:47: DEBUG: skip to trim padding.
2017-03-31 22:27:47: DEBUG: decrypted.
2017-03-31 22:27:47: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 05100201 00000000 00000044 db504ea4
e924a3bf 14bfcb3c 9a5f972c 778e7c23 3199be4d 59517584 1178312e cd29c3c7
bb1f581d
2017-03-31 22:27:47: DEBUG: begin.
2017-03-31 22:27:47: DEBUG: seen nptype=5(id)
2017-03-31 22:27:47: DEBUG: invalid length of payload
2017-03-31 22:27:51: DEBUG: 232 bytes from 10.0.0.1[4500] to 10.2.128.240[4500]
2017-03-31 22:27:51: DEBUG: sockname 10.0.0.1[4500]
2017-03-31 22:27:51: DEBUG: send packet from 10.0.0.1[4500]
2017-03-31 22:27:51: DEBUG: send packet to 10.2.128.240[4500]
2017-03-31 22:27:51: DEBUG: src4 10.0.0.1[4500]
2017-03-31 22:27:51: DEBUG: dst4 10.2.128.240[4500]
2017-03-31 22:27:51: DEBUG: 1 times of 232 bytes message will be sent to 10.2.128.240[4500]
2017-03-31 22:27:51: DEBUG: 
00000000 8c6688ca baaf90ca a8d8758b 59948609 04100200 00000000 000000e4
0a000084 7976a87d 8089219d 352ffa4d d69f70c1 0ec0f3f7 a5d414d1 1fb64759
a0ab2ae7 863da397 187568b6 8f96c008 9318cd96 717a19ad 762c68f9 dedd3956
1272f2ba a5730437 ca99dcb5 70ea58f3 f2fde99f 842c3be2 d72ae8ec 00554f9f
1b4906c1 6ed7aa45 d2a97d0b 63edba3f eab19603 8ba11b33 5e7b3877 aedb290d
1e74a18f 14000014 ac2c6815 c7c9aeb4 ce8ec064 a6f9f6ae 14000018 460c94de
5fc70b50 76215b0c 922352a2 676154b2 00000018 726781ed 383ec15b 882948ce
f0312d37 33ae662d
2017-03-31 22:27:51: DEBUG: resend phase1 packet 8c6688cabaaf90ca:a8d8758b59948609
2017-03-31 22:27:54: DEBUG: KA: 10.0.0.1[4500]->10.2.128.240[4500]
2017-03-31 22:27:54: DEBUG: sockname 10.0.0.1[4500]
2017-03-31 22:27:54: DEBUG: send packet from 10.0.0.1[4500]
2017-03-31 22:27:54: DEBUG: send packet to 10.2.128.240[4500]
2017-03-31 22:27:54: DEBUG: src4 10.0.0.1[4500]
2017-03-31 22:27:54: DEBUG: dst4 10.2.128.240[4500]
2017-03-31 22:27:54: DEBUG: 1 times of 1 bytes message will be sent to 10.2.128.240[4500]
2017-03-31 22:27:54: DEBUG: 
ff
2017-03-31 22:28:01: DEBUG: 232 bytes from 10.0.0.1[4500] to 10.2.128.240[4500]
2017-03-31 22:28:01: DEBUG: sockname 10.0.0.1[4500]
2017-03-31 22:28:01: DEBUG: send packet from 10.0.0.1[4500]
2017-03-31 22:28:01: DEBUG: send packet to 10.2.128.240[4500]
2017-03-31 22:28:01: DEBUG: src4 10.0.0.1[4500]
2017-03-31 22:28:01: DEBUG: dst4 10.2.128.240[4500]
2017-03-31 22:28:01: DEBUG: 1 times of 232 bytes message will be sent to 10.2.128.240[4500]
2017-03-31 22:28:01: DEBUG: 
00000000 8c6688ca baaf90ca a8d8758b 59948609 04100200 00000000 000000e4
0a000084 7976a87d 8089219d 352ffa4d d69f70c1 0ec0f3f7 a5d414d1 1fb64759
a0ab2ae7 863da397 187568b6 8f96c008 9318cd96 717a19ad 762c68f9 dedd3956
1272f2ba a5730437 ca99dcb5 70ea58f3 f2fde99f 842c3be2 d72ae8ec 00554f9f
1b4906c1 6ed7aa45 d2a97d0b 63edba3f eab19603 8ba11b33 5e7b3877 aedb290d
1e74a18f 14000014 ac2c6815 c7c9aeb4 ce8ec064 a6f9f6ae 14000018 460c94de
5fc70b50 76215b0c 922352a2 676154b2 00000018 726781ed 383ec15b 882948ce
f0312d37 33ae662d
2017-03-31 22:28:01: DEBUG: resend phase1 packet 8c6688cabaaf90ca:a8d8758b59948609
2017-03-31 22:28:03: DEBUG: ===
2017-03-31 22:28:03: DEBUG: 68 bytes message received from 10.2.128.240[4500] to 10.0.0.1[4500]
2017-03-31 22:28:03: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 05100201 00000000 00000044 ed0655f5
0f6c36ad 91a2c8b4 8cbc402c 55873cd1 828a756d 309ecc8e 8e2f68b1 597b1684
a3ad0453
2017-03-31 22:28:03: DEBUG: begin decryption.
2017-03-31 22:28:03: DEBUG: encryption(3des)
2017-03-31 22:28:03: DEBUG: IV was saved for next processing:
2017-03-31 22:28:03: DEBUG: 
597b1684 a3ad0453
2017-03-31 22:28:03: DEBUG: encryption(3des)
2017-03-31 22:28:03: DEBUG: with key:
2017-03-31 22:28:03: DEBUG: 
ef0edddf d49becb1 d059bfb2 c01479f5 8bf1e315 a5456312
2017-03-31 22:28:03: DEBUG: decrypted payload by IV:
2017-03-31 22:28:03: DEBUG: 
12b39be5 538407a7
2017-03-31 22:28:03: DEBUG: decrypted payload, but not trimed.
2017-03-31 22:28:03: DEBUG: 
db504ea4 e924a3bf 14bfcb3c 9a5f972c 778e7c23 3199be4d 59517584 1178312e
cd29c3c7 bb1f581d
2017-03-31 22:28:03: DEBUG: padding len=30
2017-03-31 22:28:03: DEBUG: skip to trim padding.
2017-03-31 22:28:03: DEBUG: decrypted.
2017-03-31 22:28:03: DEBUG: 
8c6688ca baaf90ca a8d8758b 59948609 05100201 00000000 00000044 db504ea4
e924a3bf 14bfcb3c 9a5f972c 778e7c23 3199be4d 59517584 1178312e cd29c3c7
bb1f581d
2017-03-31 22:28:03: DEBUG: begin.
2017-03-31 22:28:03: DEBUG: seen nptype=5(id)
2017-03-31 22:28:03: DEBUG: invalid length of payload
2017-03-31 22:28:11: DEBUG: 232 bytes from 10.0.0.1[4500] to 10.2.128.240[4500]
2017-03-31 22:28:11: DEBUG: sockname 10.0.0.1[4500]
2017-03-31 22:28:11: DEBUG: send packet from 10.0.0.1[4500]
2017-03-31 22:28:11: DEBUG: send packet to 10.2.128.240[4500]
2017-03-31 22:28:11: DEBUG: src4 10.0.0.1[4500]
2017-03-31 22:28:11: DEBUG: dst4 10.2.128.240[4500]
2017-03-31 22:28:11: DEBUG: 1 times of 232 bytes message will be sent to 10.2.128.240[4500]
2017-03-31 22:28:11: DEBUG: 
00000000 8c6688ca baaf90ca a8d8758b 59948609 04100200 00000000 000000e4
0a000084 7976a87d 8089219d 352ffa4d d69f70c1 0ec0f3f7 a5d414d1 1fb64759
a0ab2ae7 863da397 187568b6 8f96c008 9318cd96 717a19ad 762c68f9 dedd3956
1272f2ba a5730437 ca99dcb5 70ea58f3 f2fde99f 842c3be2 d72ae8ec 00554f9f
1b4906c1 6ed7aa45 d2a97d0b 63edba3f eab19603 8ba11b33 5e7b3877 aedb290d
1e74a18f 14000014 ac2c6815 c7c9aeb4 ce8ec064 a6f9f6ae 14000018 460c94de
5fc70b50 76215b0c 922352a2 676154b2 00000018 726781ed 383ec15b 882948ce
f0312d37 33ae662d
2017-03-31 22:28:11: DEBUG: resend phase1 packet 8c6688cabaaf90ca:a8d8758b59948609
2017-03-31 22:28:14: DEBUG: KA: 10.0.0.1[4500]->10.2.128.240[4500]
2017-03-31 22:28:14: DEBUG: sockname 10.0.0.1[4500]
2017-03-31 22:28:14: DEBUG: send packet from 10.0.0.1[4500]
2017-03-31 22:28:14: DEBUG: send packet to 10.2.128.240[4500]
2017-03-31 22:28:14: DEBUG: src4 10.0.0.1[4500]
2017-03-31 22:28:14: DEBUG: dst4 10.2.128.240[4500]
2017-03-31 22:28:14: DEBUG: 1 times of 1 bytes message will be sent to 10.2.128.240[4500]
2017-03-31 22:28:14: DEBUG: 
ff
2017-03-31 22:28:21: ERROR: phase1 negotiation failed due to time up. 8c6688cabaaf90ca:a8d8758b59948609
2017-03-31 22:28:21: INFO: KA remove: 10.0.0.1[4500]->10.2.128.240[4500]
2017-03-31 22:28:21: DEBUG: KA tree dump: 10.0.0.1[4500]->10.2.128.240[4500] (in_use=1)
2017-03-31 22:28:21: DEBUG: KA removing this one...
2017-03-31 22:28:21: DEBUG: IV freed
2017-03-31 22:28:35: DEBUG: ===
2017-03-31 22:28:35: DEBUG: 200 bytes message received from 10.2.128.240[500] to 10.0.0.1[500]
2017-03-31 22:28:35: DEBUG: 
2da93063 56ab7f6f 00000000 00000000 01100200 00000000 000000c8 0d000034
00000001 00000001 00000028 00010001 00000020 00010000 800b0001 800c7080
80010005 80020002 80030001 80040002 0d000014 afcad713 68a1f1c9 6b8696fc
77570100 0d000014 4048b7d5 6ebce885 25e7de7f 00d6c2d3 0d000014 4a131c81
07035845 5c5728f2 0e95452f 0d000014 7d9419a6 5310ca6f 2c179d92 15529d56
0d000014 90cb8091 3ebb696e 086381b5 ec427b1f 00000014 cd604643 35df21f8
7cfdb2fc 68b6a448
2017-03-31 22:28:35: DEBUG: ===
2017-03-31 22:28:35: INFO: respond new phase 1 negotiation: 10.0.0.1[500]<=>10.2.128.240[500]
2017-03-31 22:28:35: INFO: begin Identity Protection mode.
2017-03-31 22:28:35: DEBUG: begin.
2017-03-31 22:28:35: DEBUG: seen nptype=1(sa)
2017-03-31 22:28:35: DEBUG: seen nptype=13(vid)
2017-03-31 22:28:35: DEBUG: seen nptype=13(vid)
2017-03-31 22:28:35: DEBUG: seen nptype=13(vid)
2017-03-31 22:28:35: DEBUG: seen nptype=13(vid)
2017-03-31 22:28:35: DEBUG: seen nptype=13(vid)
2017-03-31 22:28:35: DEBUG: seen nptype=13(vid)
2017-03-31 22:28:35: DEBUG: succeed.
2017-03-31 22:28:35: INFO: received Vendor ID: DPD
2017-03-31 22:28:35: DEBUG: remote supports DPD
2017-03-31 22:28:35: INFO: received Vendor ID: FRAGMENTATION
2017-03-31 22:28:35: INFO: received Vendor ID: RFC 3947
2017-03-31 22:28:35: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-03
2017-03-31 22:28:35: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-02

2017-03-31 22:28:35: INFO: received Vendor ID: draft-ietf-ipsec-nat-t-ike-02
2017-03-31 22:28:35: [10.2.128.240] INFO: Selected NAT-T version: RFC 3947