ipsec/racoon generated policy problem
I'm trying to set up a VPN using debian sarge's distributed ipsec tools and racoon.
This is going to be a road warrior setup.
For illustrative purposes I've boiled down the problem to a minimum:
On the road warrior side (spud or 192.168.100.2):
spud$ sudo setkey -DP
192.168.100.86[any] 192.168.100.2[any] any
in ipsec
esp/tunnel/192.168.100.86-192.168.100.2/require
created: Jun 22 10:28:05 2005 lastused: Jun 22 10:33:30 2005
lifetime: 0(s) validtime: 0(s)
spid=3400 seq=2 pid=11814
refcnt=1
192.168.100.2[any] 192.168.100.86[any] any
out ipsec
esp/tunnel/192.168.100.2-192.168.100.86/require
created: Jun 22 10:28:05 2005 lastused: Jun 22 10:33:35 2005
lifetime: 0(s) validtime: 0(s)
spid=3393 seq=1 pid=11814
refcnt=1
192.168.100.86[any] 192.168.100.2[any] any
fwd ipsec
esp/tunnel/192.168.100.86-192.168.100.2/require
created: Jun 22 10:28:05 2005 lastused:
lifetime: 0(s) validtime: 0(s)
spid=3410 seq=0 pid=11814
refcnt=1
spud$ cat /etc/racoon/racoon.conf
path pre_shared_key "/etc/racoon/psk.txt";
remote 192.168.100.86 {
exchange_mode main;
proposal {
encryption_algorithm 3des;
hash_algorithm md5;
authentication_method pre_shared_key;
dh_group modp1024;
}
}
sainfo address 192.168.100.2/32 any address 192.168.100.86/32 any {
pfs_group modp1024;
encryption_algorithm 3des;
authentication_algorithm hmac_md5;
compression_algorithm deflate;
lifetime time 30 sec; # sec,min,hour NOTICE THE SHORT TIMEOUT
}
And on the VPN gateway side (blueberry or 192.168.100.86):
blueberry$ cat /etc/racoon/racoon.conf
path pre_shared_key "/etc/racoon/psk.txt";
remote 192.168.100.2 {
exchange_mode main;
generate_policy on; # NOTICE WE'RE GENERATING THE POLICY
passive on;
proposal {
encryption_algorithm 3des;
hash_algorithm md5;
authentication_method pre_shared_key;
dh_group modp1024;
}
}
sainfo address 192.168.100.86/32 any address 192.168.100.2/32 any {
pfs_group modp1024;
encryption_algorithm 3des;
authentication_algorithm hmac_md5;
compression_algorithm deflate;
}
From spud (the roadwarrior) a simple ping starts the VPN setup, and that's fine. This is the racoon output on startup on the VPN gateway (blueberry) side when it starts up.
blueberry$ sudo racoon -F
Foreground mode.
2005-06-22 10:29:07: INFO: @(#)This product linked OpenSSL 0.9.7e 25 Oct 2004 (http://www.openssl.org/)
2005-06-22 10:29:08: INFO: 127.0.0.1[500] used as isakmp port (fd=7)
2005-06-22 10:29:08: INFO: 127.0.0.1[500] used for NAT-T
2005-06-22 10:29:08: INFO: 192.168.100.86[500] used as isakmp port (fd=8)
2005-06-22 10:29:08: INFO: 192.168.100.86[500] used for NAT-T
2005-06-22 10:29:08: INFO: ::1[500] used as isakmp port (fd=9)
2005-06-22 10:29:08: INFO: fe80::202:b3ff:fecb:fdcc%eth0[500] used as isakmp port (fd=10)
2005-06-22 10:29:09: INFO: respond new phase 1 negotiation: 192.168.100.86[500]<=>192.168.100.2[500]
2005-06-22 10:29:09: INFO: begin Identity Protection mode.
2005-06-22 10:29:09: INFO: received Vendor ID: DPD
2005-06-22 10:29:09: INFO: ISAKMP-SA established 192.168.100.86[500]-192.168.100.2[500] spi:0353f9860a8ac5b8:140c63124535e6a7
2005-06-22 10:29:10: INFO: respond new phase 2 negotiation: 192.168.100.86[0]<=>192.168.100.2[0]
2005-06-22 10:29:10: INFO: no policy found, try to generate the policy : 192.168.100.2/32[0] 192.168.100.86/32[0] proto=any dir=in
2005-06-22 10:29:10: INFO: IPsec-SA established: ESP/Tunnel 192.168.100.2->192.168.100.86 spi=188999471(0xb43e72f)
2005-06-22 10:29:10: INFO: IPsec-SA established: ESP/Tunnel 192.168.100.86->192.168.100.2 spi=34668489(0x210ffc9)
2005-06-22 10:29:10: ERROR: such policy does not already exist: 192.168.100.2/32[0] 192.168.100.86/32[0] proto=any dir=in
2005-06-22 10:29:10: ERROR: such policy does not already exist: 192.168.100.2/32[0] 192.168.100.86/32[0] proto=any dir=fwd
2005-06-22 10:29:10: ERROR: such policy does not already exist: 192.168.100.86/32[0] 192.168.100.2/32[0] proto=any dir=out
I leave the ping from the roadwarrior going and watch the outputs of the racoons on both sides. When the 30 second timeout is coming up, a renegotiation of phase 2 starts. Sometimes this works fine - the ping just continues to go through... but eventually it goes wrong. The log outputs on both sides does not indicate that anything has gone wrong.
The VPN gateway side (blueberry) logs:
The following is a successfull renegotiation:
2005-06-22 11:13:19: INFO: IPsec-SA expired: ESP/Tunnel 192.168.100.2->192.168.100.86 spi=210930990(0xc928d2e)
2005-06-22 11:13:19: INFO: respond new phase 2 negotiation: 192.168.100.86[0]<=>192.168.100.2[0]
2005-06-22 11:13:19: INFO: Update the generated policy : 192.168.100.2/32[0] 192.168.100.86/32[0] proto=any dir=in
2005-06-22 11:13:19: INFO: IPsec-SA expired: ESP/Tunnel 192.168.100.86->192.168.100.2 spi=1211258(0x127b7a)
2005-06-22 11:13:19: INFO: IPsec-SA established: ESP/Tunnel 192.168.100.2->192.168.100.86 spi=23946995(0x16d66f3)
2005-06-22 11:13:19: INFO: IPsec-SA established: ESP/Tunnel 192.168.100.86->192.168.100.2 spi=251544247(0xefe42b7)
2005-06-22 11:13:19: ERROR: such policy does not already exist: 192.168.100.2/32[0] 192.168.100.86/32[0] proto=any dir=in
2005-06-22 11:13:19: ERROR: such policy does not already exist: 192.168.100.2/32[0] 192.168.100.86/32[0] proto=any dir=fwd
2005-06-22 11:13:19: ERROR: such policy does not already exist: 192.168.100.86/32[0] 192.168.100.2/32[0] proto=any dir=out
A bit later:
2005-06-22 11:13:25: INFO: IPsec-SA expired: ESP/Tunnel 192.168.100.2->192.168.100.86 spi=210930990(0xc928d2e)
2005-06-22 11:13:25: INFO: IPsec-SA expired: ESP/Tunnel 192.168.100.86->192.168.100.2 spi=1211258(0x127b7a)
The ping stops just when this renegotiation starts:
2005-06-22 11:13:43: INFO: IPsec-SA expired: ESP/Tunnel 192.168.100.2->192.168.100.86 spi=23946995(0x16d66f3)
2005-06-22 11:13:43: INFO: respond new phase 2 negotiation: 192.168.100.86[0]<=>192.168.100.2[0]
2005-06-22 11:13:43: INFO: Update the generated policy : 192.168.100.2/32[0] 192.168.100.86/32[0] proto=any dir=in
2005-06-22 11:13:44: INFO: IPsec-SA expired: ESP/Tunnel 192.168.100.86->192.168.100.2 spi=251544247(0xefe42b7)
2005-06-22 11:13:44: INFO: IPsec-SA established: ESP/Tunnel 192.168.100.2->192.168.100.86 spi=164715331(0x9d15b43)
2005-06-22 11:13:44: INFO: IPsec-SA established: ESP/Tunnel 192.168.100.86->192.168.100.2 spi=60103856(0x3951cb0)
2005-06-22 11:13:44: ERROR: such policy does not already exist: 192.168.100.2/32[0] 192.168.100.86/32[0] proto=any dir=in
2005-06-22 11:13:44: ERROR: such policy does not already exist: 192.168.100.2/32[0] 192.168.100.86/32[0] proto=any dir=fwd
2005-06-22 11:13:44: ERROR: such policy does not already exist: 192.168.100.86/32[0] 192.168.100.2/32[0] proto=any dir=out
A little later (but not important)
2005-06-22 11:13:49: INFO: IPsec-SA expired: ESP/Tunnel 192.168.100.2->192.168.100.86 spi=23946995(0x16d66f3)
2005-06-22 11:13:49: INFO: IPsec-SA expired: ESP/Tunnel 192.168.100.86->192.168.100.2 spi=251544247(0xefe42b7)
When the problem occurs, the auto generated policy on the VPN-gw (blueberry) is gone:
When it is working:
blueberry$ sudo setkey -DP
192.168.100.2[any] 192.168.100.86[any] any
in ipsec
esp/tunnel/192.168.100.2-192.168.100.86/require
created: Jun 22 11:13:19 2005 lastused: Jun 22 11:13:34 2005
lifetime: 30(s) validtime: 0(s)
spid=864 seq=10 pid=10959
refcnt=3
192.168.100.86[any] 192.168.100.2[any] any
out ipsec
esp/tunnel/192.168.100.86-192.168.100.2/require
created: Jun 22 11:13:19 2005 lastused: Jun 22 11:13:34 2005
lifetime: 30(s) validtime: 0(s)
spid=881 seq=9 pid=10959
refcnt=3
192.168.100.2[any] 192.168.100.86[any] any
fwd ipsec
esp/tunnel/192.168.100.2-192.168.100.86/require
created: Jun 22 11:13:19 2005 lastused:
lifetime: 30(s) validtime: 0(s)
spid=874 seq=8 pid=10959
refcnt=2
... (and then all the per-socket policy)
But when it stops:
blueberry$ sudo setkey -DP
... (just per-socket policies left)
Timing wise this happens when the renegotiation starts, and not when the "IPsec-SA expired" log message comes a little later.
Wednesday, 6 October 2004
