IPSEC site-to-site doesn't work after phase2 sa expired
-
Hi everybody,
i don't understand why my ipsec vpn tunnel goes down after first "phase2 sa expired" and there's no way to restart again my tunnel.
My scenario.
Site A (peer 1.1.1.1)
Mode Tunnel
Interface WAN
DPD interval 60 seconds
Local subnet 192.168.100.0/24
Remote subnet 192.168.1.0/24
Remote gateway 2.2.2.2Phase 1 proposal (Authentication)
Negotiation mode Aggressive
My identifier MyIPAddress
Encryption algorithm 3DES
Hash algorithm SHA1
DH key group 2
Lifetime 28800 seconds
Authentication method Pre-Shared Key
Pre-Shared Key mysecretPhase 2 proposal (SA/Key Exchange)
Protocol ESP
Encryption algorithms 3DES
Hash algorithms MD5
PFS key group 2
Lifetime 3600 secondsSite B (peer 2.2.2.2, *there is a 1-to-1 nat to 192.168.150.10 <- WAN Address in pfsense)
Mode Tunnel
Interface WAN
DPD interval 60 seconds
Local subnet 192.168.1.0/24
Remote subnet 192.168.100.0/24
Remote gateway 1.1.1.1Phase 1 proposal (Authentication)
Negotiation mode Aggressive
My identifier MyIPAddress
Encryption algorithm 3DES
Hash algorithm SHA1
DH key group 2
Lifetime 28800 seconds
Authentication method Pre-Shared Key
Pre-Shared Key mysecretPhase 2 proposal (SA/Key Exchange)
Protocol ESP
Encryption algorithms 3DES
Hash algorithms MD5
PFS key group 2
Lifetime 3600 secondsThese are ACTUAL /var/etc/racoon.conf files of
Site A
listen {
adminsock "/var/db/racoon/racoon.sock" "root" "wheel" 0660;
}
path pre_shared_key "/var/etc/psk.txt";path certificate "/var/etc";
remote 2.2.2.2 {
exchange_mode aggressive;
my_identifier address "1.1.1.1";peers_identifier address 2.2.2.2;
initial_contact on;
dpd_delay 60;
ike_frag on;
support_proxy on;
proposal_check obey;proposal {
encryption_algorithm 3des;
hash_algorithm sha1;
authentication_method pre_shared_key;
dh_group 2;
lifetime time 28800 secs;
}
lifetime time 28800 secs;
}sainfo address 192.168.100.0/24 any address 10.192.1.0/24 any {
encryption_algorithm 3des;
authentication_algorithm hmac_md5;
compression_algorithm deflate;
pfs_group 2;
lifetime time 3600 secs;
}Site B
listen {
adminsock "/var/db/racoon/racoon.sock" "root" "wheel" 0660;
}
path pre_shared_key "/var/etc/psk.txt";path certificate "/var/etc";
remote 1.1.1.1 {
exchange_mode aggressive;
my_identifier address "192.168.150.10";peers_identifier address 1.1.1.1;
initial_contact on;
dpd_delay 60;
ike_frag on;
support_proxy on;
proposal_check obey;proposal {
encryption_algorithm 3des;
hash_algorithm sha1;
authentication_method pre_shared_key;
dh_group 2;
lifetime time 28800 secs;
}
lifetime time 28800 secs;
}sainfo address 192.168.1.0/24 any address 192.168.100.0/24 any {
encryption_algorithm 3des;
authentication_algorithm hmac_md5;
compression_algorithm deflate;
pfs_group 2;
lifetime time 3600 secs;
}In my first setup, no lifetime were setup for both sites.
Everything works until today… this is last working log of site AMar 1 14:48:56 racoon: [Self]: INFO: 1.1.1.1[500] used as isakmp port (fd=15)
Mar 1 14:48:56 racoon: [Self]: INFO: 192.168.100.1[500] used as isakmp port (fd=16)
Mar 1 14:48:56 racoon: INFO: unsupported PF_KEY message REGISTER
Mar 1 14:48:56 racoon: ERROR: such policy already exists. anyway replace it: 192.168.100.0/24[0] 192.168.1.0/24[0] proto=any dir=out
Mar 1 14:48:56 racoon: ERROR: such policy already exists. anyway replace it: 192.168.1.0/24[0] 192.168.100.0/24[0] proto=any dir=in
Mar 1 14:48:56 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
Mar 1 14:48:56 racoon: [Self]: INFO: 1.1.1.1[500] used as isakmp port (fd=15)
Mar 1 14:48:56 racoon: [Self]: INFO: 192.168.100.1[500] used as isakmp port (fd=16)
Mar 1 14:49:56 racoon: [VPN Tunnel to Site B]: INFO: respond new phase 1 negotiation: 1.1.1.1[500]<=>2.2.2.2[500]
Mar 1 14:49:56 racoon: INFO: begin Aggressive mode.
Mar 1 14:49:56 racoon: INFO: received broken Microsoft ID: FRAGMENTATION
Mar 1 14:49:56 racoon: INFO: received Vendor ID: DPD
Mar 1 14:49:56 racoon: WARNING: No ID match.
Mar 1 14:49:56 racoon: NOTIFY: couldn't find the proper pskey, try to get one by the peer's address.
Mar 1 14:49:56 racoon: [VPN Tunnel to Site B]: INFO: ISAKMP-SA established 1.1.1.1[500]-2.2.2.2[500] spi:e81e2895e3a3c672:cee809c23053a564
Mar 1 14:49:57 racoon: [VPN Tunnel to Site B]: INFO: respond new phase 2 negotiation: 1.1.1.1[0]<=>2.2.2.2[0]
Mar 1 14:49:57 racoon: [VPN Tunnel to Site B]: INFO: IPsec-SA established: ESP 2.2.2.2[0]->1.1.1.1[0] spi=156106193(0x94dfdd1)
Mar 1 14:49:57 racoon: [VPN Tunnel to Site B]: INFO: IPsec-SA established: ESP 1.1.1.1[0]->2.2.2.2[0] spi=128354211(0x7a687a3)
Mar 1 21:13:58 racoon: [VPN Tunnel to Site B]: INFO: IPsec-SA expired: ESP 1.1.1.1[0]->2.2.2.2[0] spi=128354211(0x7a687a3)
Mar 1 21:13:58 racoon: [VPN Tunnel to Site B]: INFO: IPsec-SA expired: ESP/Tunnel 2.2.2.2[0]->1.1.1.1[0] spi=156106193(0x94dfdd1)
Mar 1 21:13:58 racoon: [VPN Tunnel to Site B]: INFO: respond new phase 2 negotiation: 1.1.1.1[0]<=>2.2.2.2[0]
Mar 1 21:13:59 racoon: [VPN Tunnel to Site B]: INFO: IPsec-SA established: ESP 2.2.2.2[0]->1.1.1.1[0] spi=138429856(0x84045a0)
Mar 1 21:13:59 racoon: [VPN Tunnel to Site B]: INFO: IPsec-SA established: ESP 1.1.1.1[0]->2.2.2.2[0] spi=186944455(0xb248bc7)
Mar 1 22:49:56 racoon: [VPN Tunnel to Site B]: INFO: ISAKMP-SA expired 1.1.1.1[500]-2.2.2.2[500] spi:e81e2895e3a3c672:cee809c23053a564
Mar 1 22:49:57 racoon: [VPN Tunnel to Site B]: INFO: ISAKMP-SA deleted 1.1.1.1[500]-2.2.2.2[500] spi:e81e2895e3a3c672:cee809c23053a564
Mar 2 05:14:00 racoon: [VPN Tunnel to Site B]: INFO: phase2 sa expired 1.1.1.1-2.2.2.2
Mar 2 05:14:01 racoon: [VPN Tunnel to Site B]: INFO: phase2 sa deleted 1.1.1.1-2.2.2.2
Mar 2 11:45:01 racoon: INFO: unsupported PF_KEY message REGISTER
Mar 2 11:45:01 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
Mar 2 11:45:01 racoon: [Self]: INFO: 1.1.1.1[500] used as isakmp port (fd=15)
Mar 2 11:45:01 racoon: [Self]: INFO: 192.168.100.1[500] used as isakmp port (fd=16)
Mar 2 11:47:19 racoon: INFO: unsupported PF_KEY message REGISTER
Mar 2 11:47:20 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
Mar 2 11:47:20 racoon: [Self]: INFO: 1.1.1.1[500] used as isakmp port (fd=15)
Mar 2 11:47:20 racoon: [Self]: INFO: 192.168.100.1[500] used as isakmp port (fd=16)
Mar 2 11:48:53 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
Mar 2 11:48:53 racoon: [Self]: INFO: 1.1.1.1[500] used as isakmp port (fd=15)
Mar 2 11:48:53 racoon: [Self]: INFO: 192.168.100.1[500] used as isakmp port (fd=16)
Mar 2 11:48:53 racoon: INFO: caught signal 15
Mar 2 11:48:54 racoon: INFO: racoon shutdown
Mar 2 11:48:59 racoon: INFO: @(#)ipsec-tools 0.7.2 (http://ipsec-tools.sourceforge.net)
Mar 2 11:48:59 racoon: INFO: @(#)This product linked OpenSSL 0.9.8e 23 Feb 2007 (http://www.openssl.org/)
Mar 2 11:48:59 racoon: INFO: Reading configuration from "/var/etc/racoon.conf"
Mar 2 11:48:59 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
Mar 2 11:48:59 racoon: [Self]: INFO: 1.1.1.1[500] used as isakmp port (fd=15)
Mar 2 11:48:59 racoon: [Self]: INFO: 192.168.100.1[500] used as isakmp port (fd=16)
Mar 2 11:48:59 racoon: INFO: unsupported PF_KEY message REGISTER
Mar 2 11:48:59 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
Mar 2 11:48:59 racoon: [Self]: INFO: 1.1.1.1[500] used as isakmp port (fd=15)
Mar 2 11:48:59 racoon: [Self]: INFO: 192.168.100.1[500] used as isakmp port (fd=16)and this is last working log of site B
Mar 1 14:49:18 racoon: [Self]: INFO: 192.168.150.10[500] used as isakmp port (fd=15)
Mar 1 14:49:18 racoon: [Self]: INFO: 192.168.1.50[500] used as isakmp port (fd=16)
Mar 1 14:49:18 racoon: INFO: unsupported PF_KEY message REGISTER
Mar 1 14:49:18 racoon: ERROR: such policy already exists. anyway replace it: 192.168.1.0/24[0] 192.168.100.0/24[0] proto=any dir=out
Mar 1 14:49:18 racoon: ERROR: such policy already exists. anyway replace it: 192.168.100.0/24[0] 192.168.1.0/24[0] proto=any dir=in
Mar 1 14:49:18 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
Mar 1 14:49:18 racoon: [Self]: INFO: 192.168.150.10[500] used as isakmp port (fd=15)
Mar 1 14:49:18 racoon: [Self]: INFO: 192.168.1.50[500] used as isakmp port (fd=16)
Mar 1 14:49:56 racoon: [VPN Tunnel to Site A]: INFO: IPsec-SA request for 1.1.1.1 queued due to no phase1 found.
Mar 1 14:49:56 racoon: [VPN Tunnel to Site A]: INFO: initiate new phase 1 negotiation: 192.168.150.10[500]<=>1.1.1.1[500]
Mar 1 14:49:56 racoon: INFO: begin Aggressive mode.
Mar 1 14:49:56 racoon: INFO: received broken Microsoft ID: FRAGMENTATION
Mar 1 14:49:56 racoon: INFO: received Vendor ID: DPD
Mar 1 14:49:56 racoon: NOTIFY: couldn't find the proper pskey, try to get one by the peer's address.
Mar 1 14:49:56 racoon: [VPN Tunnel to Site A]: INFO: ISAKMP-SA established 192.168.150.10[500]-1.1.1.1[500] spi:e81e2895e3a3c672:cee809c23053a564
Mar 1 14:49:57 racoon: [VPN Tunnel to Site A]: INFO: initiate new phase 2 negotiation: 192.168.150.10[500]<=>1.1.1.1[500]
Mar 1 14:49:57 racoon: [VPN Tunnel to Site A]: INFO: IPsec-SA established: ESP 1.1.1.1[0]->192.168.150.10[0] spi=128354211(0x7a687a3)
Mar 1 14:49:57 racoon: [VPN Tunnel to Site A]: INFO: IPsec-SA established: ESP 192.168.150.10[0]->1.1.1.1[0] spi=156106193(0x94dfdd1)
Mar 1 21:13:58 racoon: [VPN Tunnel to Site A]: INFO: IPsec-SA expired: ESP 192.168.150.10[0]->1.1.1.1[0] spi=156106193(0x94dfdd1)
Mar 1 21:13:58 racoon: [VPN Tunnel to Site A]: INFO: initiate new phase 2 negotiation: 192.168.150.10[0]<=>1.1.1.1[0]
Mar 1 21:13:58 racoon: [VPN Tunnel to Site A]: INFO: IPsec-SA expired: ESP/Tunnel 1.1.1.1[0]->192.168.150.10[0] spi=128354211(0x7a687a3)
Mar 1 21:13:58 racoon: [VPN Tunnel to Site A]: INFO: IPsec-SA established: ESP 1.1.1.1[0]->192.168.150.10[0] spi=186944455(0xb248bc7)
Mar 1 21:13:58 racoon: [VPN Tunnel to Site A]: INFO: IPsec-SA established: ESP 192.168.150.10[0]->1.1.1.1[0] spi=138429856(0x84045a0)
Mar 1 22:49:56 racoon: [VPN Tunnel to Site A]: INFO: ISAKMP-SA expired 192.168.150.10[500]-1.1.1.1[500] spi:e81e2895e3a3c672:cee809c23053a564
Mar 1 22:49:57 racoon: [VPN Tunnel to Site A]: INFO: ISAKMP-SA deleted 192.168.150.10[500]-1.1.1.1[500] spi:e81e2895e3a3c672:cee809c23053a564
Mar 2 05:13:58 racoon: [VPN Tunnel to Site A]: INFO: phase2 sa expired 192.168.150.10-1.1.1.1
Mar 2 05:13:59 racoon: [VPN Tunnel to Site A]: INFO: phase2 sa deleted 192.168.150.10-1.1.1.1
Mar 2 11:45:19 racoon: INFO: unsupported PF_KEY message REGISTER
Mar 2 11:45:19 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
Mar 2 11:45:19 racoon: [Self]: INFO: 192.168.150.10[500] used as isakmp port (fd=15)
Mar 2 11:45:19 racoon: [Self]: INFO: 192.168.1.50[500] used as isakmp port (fd=16)
Mar 2 11:47:32 racoon: INFO: unsupported PF_KEY message REGISTER
Mar 2 11:47:32 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
Mar 2 11:47:32 racoon: [Self]: INFO: 192.168.150.10[500] used as isakmp port (fd=15)
Mar 2 11:47:32 racoon: [Self]: INFO: 192.168.1.50[500] used as isakmp port (fd=16)
Mar 2 11:48:43 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
Mar 2 11:48:43 racoon: [Self]: INFO: 192.168.150.10[500] used as isakmp port (fd=15)
Mar 2 11:48:43 racoon: [Self]: INFO: 192.168.1.50[500] used as isakmp port (fd=16)
Mar 2 11:48:43 racoon: INFO: caught signal 15
Mar 2 11:48:44 racoon: INFO: racoon shutdown
Mar 2 11:48:57 racoon: INFO: @(#)ipsec-tools 0.7.2 (http://ipsec-tools.sourceforge.net)
Mar 2 11:48:57 racoon: INFO: @(#)This product linked OpenSSL 0.9.8e 23 Feb 2007 (http://www.openssl.org/)
Mar 2 11:48:57 racoon: INFO: Reading configuration from "/var/etc/racoon.conf"
Mar 2 11:48:57 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
Mar 2 11:48:57 racoon: [Self]: INFO: 192.168.150.10[500] used as isakmp port (fd=15)
Mar 2 11:48:57 racoon: [Self]: INFO: 192.168.1.50[500] used as isakmp port (fd=16)
Mar 2 11:48:57 racoon: INFO: unsupported PF_KEY message REGISTER
Mar 2 11:48:57 racoon: [Self]: INFO: 127.0.0.1[500] used as isakmp port (fd=14)
Mar 2 11:48:57 racoon: [Self]: INFO: 192.168.150.10[500] used as isakmp port (fd=15)
Mar 2 11:48:57 racoon: [Self]: INFO: 192.168.1.50[500] used as isakmp port (fd=16)After ISAKMP-SA expired messages, i've added lifetime for phase 1 and phase 2, but no luck :(
This is racoon in debug mode on site A:
2011-03-02 17:44:09: INFO: @(#)ipsec-tools 0.7.2 (http://ipsec-tools.sourceforge.net)
2011-03-02 17:44:09: INFO: @(#)This product linked OpenSSL 0.9.8e 23 Feb 2007 (http://www.openssl.org/)
2011-03-02 17:44:09: INFO: Reading configuration from "/var/etc/racoon.conf"
2011-03-02 17:44:09: DEBUG: call pfkey_send_register for AH
2011-03-02 17:44:09: DEBUG: call pfkey_send_register for ESP
2011-03-02 17:44:09: DEBUG: call pfkey_send_register for IPCOMP
2011-03-02 17:44:09: DEBUG: reading config file /var/etc/racoon.conf
2011-03-02 17:44:09: DEBUG: hmac(modp1024)
2011-03-02 17:44:09: DEBUG: compression algorithm can not be checked because sadb message doesn't support it.
2011-03-02 17:44:09: DEBUG: getsainfo params: loc='192.168.100.0/24', rmt='10.192.1.0/24', peer='NULL', id=0
2011-03-02 17:44:09: DEBUG: getsainfo pass #2
2011-03-02 17:44:09: DEBUG: open /var/db/racoon/racoon.sock as racoon management.
2011-03-02 17:44:09: DEBUG: my interface: 192.168.100.1 (vge0)
2011-03-02 17:44:09: DEBUG: my interface: 1.1.1.1 (re0)
2011-03-02 17:44:09: DEBUG: my interface: 127.0.0.1 (lo0)
2011-03-02 17:44:09: DEBUG: configuring default isakmp port.
2011-03-02 17:44:09: DEBUG: 3 addrs are configured successfully
2011-03-02 17:44:09: INFO: 127.0.0.1[500] used as isakmp port (fd=7)
2011-03-02 17:44:09: INFO: 1.1.1.1[500] used as isakmp port (fd=8)
2011-03-02 17:44:09: INFO: 192.168.100.1[500] used as isakmp port (fd=9)
2011-03-02 17:44:09: DEBUG: pk_recv: retry[0] recv()
2011-03-02 17:44:09: DEBUG: get pfkey X_SPDDUMP message
2011-03-02 17:44:09: DEBUG: pk_recv: retry[0] recv()
2011-03-02 17:44:09: DEBUG: get pfkey X_SPDDUMP message
2011-03-02 17:44:09: DEBUG: sub:0xbfbfe5b4: 192.168.100.1/32[0] 192.168.100.0/24[0] proto=any dir=out
2011-03-02 17:44:09: DEBUG: db :0x2853c118: 192.168.100.0/24[0] 192.168.100.1/32[0] proto=any dir=inon site B:
2011-03-02 17:44:21: INFO: @(#)ipsec-tools 0.7.2 (http://ipsec-tools.sourceforge.net)
2011-03-02 17:44:21: INFO: @(#)This product linked OpenSSL 0.9.8e 23 Feb 2007 (http://www.openssl.org/)
2011-03-02 17:44:21: INFO: Reading configuration from "/var/etc/racoon.conf"
2011-03-02 17:44:21: DEBUG: call pfkey_send_register for AH
2011-03-02 17:44:21: DEBUG: call pfkey_send_register for ESP
2011-03-02 17:44:21: DEBUG: call pfkey_send_register for IPCOMP
2011-03-02 17:44:21: DEBUG: reading config file /var/etc/racoon.conf
2011-03-02 17:44:21: DEBUG: hmac(modp1024)
2011-03-02 17:44:21: DEBUG: compression algorithm can not be checked because sadb message doesn't support it.
2011-03-02 17:44:21: DEBUG: getsainfo params: loc='192.168.1.0/24', rmt='192.168.100.0/24', peer='NULL', id=0
2011-03-02 17:44:21: DEBUG: getsainfo pass #2
2011-03-02 17:44:21: DEBUG: open /var/db/racoon/racoon.sock as racoon management.
2011-03-02 17:44:21: DEBUG: my interface: 192.168.1.50 (vge0)
2011-03-02 17:44:21: DEBUG: my interface: 192.168.150.10 (re0)
2011-03-02 17:44:21: DEBUG: my interface: 127.0.0.1 (lo0)
2011-03-02 17:44:21: DEBUG: configuring default isakmp port.
2011-03-02 17:44:21: DEBUG: 3 addrs are configured successfully
2011-03-02 17:44:21: INFO: 127.0.0.1[500] used as isakmp port (fd=7)
2011-03-02 17:44:21: INFO: 192.168.150.10[500] used as isakmp port (fd=8)
2011-03-02 17:44:21: INFO: 192.168.1.50[500] used as isakmp port (fd=9)
2011-03-02 17:44:21: DEBUG: pk_recv: retry[0] recv()
2011-03-02 17:44:21: DEBUG: get pfkey X_SPDDUMP message
2011-03-02 17:44:21: DEBUG: pk_recv: retry[0] recv()
2011-03-02 17:44:21: DEBUG: get pfkey X_SPDDUMP message
2011-03-02 17:44:21: DEBUG: sub:0xbfbfe5b4: 192.168.1.50/32[0] 192.168.1.0/24[0] proto=any dir=out
2011-03-02 17:44:21: DEBUG: db :0x2853c118: 192.168.1.0/24[0] 192.168.1.50/32[0] proto=any dir=inNo other messages are available.
Can anyone tell me where i'm wrong??
Sierra