Hello,
I have problem with IPSec between 2.6.x Linux native IPsec and Linksys BEFSX41
router. Everything works fine until key renegotiation. Routers are able to
exchange keys & setup IPSec connection:
Feb 11 12:29:16 gw1 racoon: INFO: @(#)ipsec-tools 0.4
(http://ipsec-tools.sourceforge.net)
Feb 11 12:29:16 gw1 racoon: INFO: @(#)This product linked OpenSSL 0.9.7e 25 Oct
2004 (http://www.openssl.org/)
Feb 11 12:29:16 gw1 racoon: INFO: BBB.BB.BB.BB[500] used as isakmp port (fd=7)
Feb 11 12:29:16 gw1 racoon: INFO: IPsec-SA request for AA.AA.AAA.AAA queued due
to no phase1 found.
Feb 11 12:29:16 gw1 racoon: INFO: initiate new phase 1 negotiation:
BBB.BB.BB.BB[500]<=>AA.AA.AAA.AAA[500]
Feb 11 12:29:16 gw1 racoon: INFO: begin Identity Protection mode.
Feb 11 12:29:19 gw1 racoon: INFO: ISAKMP-SA established
BBB.BB.BB.BB[500]-AA.AA.AAA.AAA[500] spi:5e657591032b23ce:3f6df2be5d610c99
Feb 11 12:29:20 gw1 racoon: INFO: initiate new phase 2 negotiation:
BBB.BB.BB.BB[0]<=>AA.AA.AAA.AAA[0]
Feb 11 12:29:22 gw1 racoon: WARNING: attribute has been modified.
Feb 11 12:29:22 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
AA.AA.AAA.AAA->BBB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 12:29:22 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
BBB.BB.BB.BB->AA.AA.AAA.AAA spi=1042970307(0x3e2a76c3)
After 48 minutes (hard limit is 3600s and soft 2880s) racoon starts negotiating
new keys and then tunnel stops working.
Feb 11 13:17:22 gw1 racoon: INFO: IPsec-SA expired: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:17:22 gw1 racoon: INFO: IPsec-SA request for AA.AA.AAA.AAA queued due
to no phase1 found.
Feb 11 13:17:22 gw1 racoon: INFO: initiate new phase 1 negotiation:
BB.BB.BB.BB[500]<=>AA.AA.AAA.AAA[500]
Feb 11 13:17:22 gw1 racoon: INFO: begin Identity Protection mode.
Feb 11 13:17:22 gw1 racoon: INFO: IPsec-SA expired: ESP/Tunnel
BB.BB.BB.BB->AA.AA.AAA.AAA spi=1042970307(0x3e2a76c3)
Feb 11 13:17:31 gw1 racoon: INFO: ISAKMP-SA established
BB.BB.BB.BB[500]-AA.AA.AAA.AAA[500] spi:14cb86caec437624:0c11453a860aa178
Feb 11 13:17:32 gw1 racoon: INFO: initiate new phase 2 negotiation:
BB.BB.BB.BB[0]<=>AA.AA.AAA.AAA[0]
Feb 11 13:17:35 gw1 racoon: WARNING: attribute has been modified.
Feb 11 13:17:35 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:17:35 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
BB.BB.BB.BB->AA.AA.AAA.AAA spi=456046736(0x1b2eb890)
Feb 11 13:17:36 gw1 racoon: INFO: IPsec-SA expired: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:17:36 gw1 racoon: INFO: initiate new phase 2 negotiation:
BB.BB.BB.BB[0]<=>AA.AA.AAA.AAA[0]
Feb 11 13:17:48 gw1 racoon: WARNING: attribute has been modified.
Feb 11 13:17:48 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:17:48 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
BB.BB.BB.BB->AA.AA.AAA.AAA spi=984883126(0x3ab41fb6)
Feb 11 13:17:49 gw1 racoon: INFO: IPsec-SA expired: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:17:49 gw1 racoon: INFO: initiate new phase 2 negotiation:
BB.BB.BB.BB[0]<=>AA.AA.AAA.AAA[0]
Feb 11 13:17:50 gw1 racoon: WARNING: attribute has been modified.
Feb 11 13:17:50 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:17:50 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
BB.BB.BB.BB->AA.AA.AAA.AAA spi=2443714535(0x91a81fe7)
Feb 11 13:17:51 gw1 racoon: INFO: IPsec-SA expired: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:17:51 gw1 racoon: INFO: initiate new phase 2 negotiation:
BB.BB.BB.BB[0]<=>AA.AA.AAA.AAA[0]
Feb 11 13:17:52 gw1 racoon: WARNING: attribute has been modified.
Feb 11 13:17:52 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:17:52 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
BB.BB.BB.BB->AA.AA.AAA.AAA spi=891474119(0x3522d0c7)
Feb 11 13:17:53 gw1 racoon: INFO: IPsec-SA expired: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:17:53 gw1 racoon: INFO: initiate new phase 2 negotiation:
BB.BB.BB.BB[0]<=>AA.AA.AAA.AAA[0]
Feb 11 13:17:56 gw1 racoon: WARNING: attribute has been modified.
Feb 11 13:17:56 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:17:56 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
BB.BB.BB.BB->AA.AA.AAA.AAA spi=3294034757(0xc456fb45)
Feb 11 13:17:57 gw1 racoon: INFO: IPsec-SA expired: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:17:57 gw1 racoon: INFO: initiate new phase 2 negotiation:
BB.BB.BB.BB[0]<=>AA.AA.AAA.AAA[0]
Feb 11 13:17:59 gw1 racoon: WARNING: attribute has been modified.
Feb 11 13:17:59 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:17:59 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
BB.BB.BB.BB->AA.AA.AAA.AAA spi=1251852702(0x4a9dc19e)
Feb 11 13:18:00 gw1 racoon: INFO: IPsec-SA expired: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:18:00 gw1 racoon: INFO: initiate new phase 2 negotiation:
BB.BB.BB.BB[0]<=>AA.AA.AAA.AAA[0]
Feb 11 13:18:02 gw1 racoon: WARNING: attribute has been modified.
Feb 11 13:18:02 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:18:02 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
BB.BB.BB.BB->AA.AA.AAA.AAA spi=522496593(0x1f24aa51)
Feb 11 13:18:03 gw1 racoon: INFO: IPsec-SA expired: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:18:03 gw1 racoon: INFO: initiate new phase 2 negotiation:
BB.BB.BB.BB[0]<=>AA.AA.AAA.AAA[0]
Feb 11 13:18:06 gw1 racoon: WARNING: attribute has been modified.
Feb 11 13:18:06 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:18:06 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
BB.BB.BB.BB->AA.AA.AAA.AAA spi=1163930963(0x45602d53)
Feb 11 13:18:07 gw1 racoon: INFO: IPsec-SA expired: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:18:07 gw1 racoon: INFO: initiate new phase 2 negotiation:
BB.BB.BB.BB[0]<=>AA.AA.AAA.AAA[0]
Feb 11 13:18:08 gw1 racoon: WARNING: attribute has been modified.
Feb 11 13:18:08 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:18:08 gw1 racoon: INFO: IPsec-SA established: ESP/Tunnel
BB.BB.BB.BB->AA.AA.AAA.AAA spi=3167100563(0xbcc61e93)
Feb 11 13:18:09 gw1 racoon: INFO: IPsec-SA expired: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:18:09 gw1 racoon: INFO: initiate new phase 2 negotiation:
BB.BB.BB.BB[0]<=>AA.AA.AAA.AAA[0]
(...)
<more messages like those>
(...)
Feb 11 13:23:46 gw1 racoon: ERROR: AA.AA.AAA.AAA give up to get IPsec-SA due to
time up to wait.
and finally...
Feb 11 13:29:22 gw1 racoon: INFO: IPsec-SA expired: ESP/Tunnel
AA.AA.AAA.AAA->BB.BB.BB.BB spi=151969078(0x90edd36)
Feb 11 13:29:22 gw1 racoon: INFO: IPsec-SA expired: ESP/Tunnel
BB.BB.BB.BB->AA.AA.AAA.AAA spi=1042970307(0x3e2a76c3)
And then I need to restart reacoon.
I have already asked this question Ipsec-tools-devel ML but after some
additional test it seems that this it may be a bug in IPsec implementatnio
on Linux - this tunnel works just fine on FreeBSD 4.10 & both racoons from
KAME & ipsec-tools package. I tested Linux 2.4.10, 2.4.11-rc (1,2,3 & 4)
and finally 2.4.11 kernel, but this problem still exists.
As far as I understand linux IPSec code, when a SA's soft limit is reached
kernel sends notification to userspace daemon (racoon for example) and
asks it to get a new SA. I have changed expiration time to much smaller
values (hard: 120s, soft: 96s) and found that "renegotiation loop" only
exists in 96s-120s window. After 120s both SAs
(AA.AA.AAA.AAA->BBB.BB.BB.BB & BBB.BB.BB.BB->AA.AA.AAA.AAA) are removed
and then renegotiation loop stops. It is not clear to my why kernel tels
racoon about SA expiration more than once and why racoon can't simply
ignores additional messages?
Anyway, such behavior can also be sometimes observerd between my two Linux
routers but it happend very, very rarely.
Best regards,
Krzysztof Olędzki
|