This is a multipart MIME message.

--==_Exmh_22412736133850
Content-Type: text/plain; charset=us-ascii


I looked a bit deeper and found that the inconsistency was triggered
by a slight time correction on one side (a laptop which was just booting).
The laptop considered its SAs expired then and started a new negotiation.
The other side (the gateway) didn't get noticed about the expiration
and added additional SAs into the SAD.
I'll append some syslog output from both sides.

best regards
Matthias



--==_Exmh_22412736133850
Content-Type: text/plain ; name="msgs.gateway"; charset=us-ascii
Content-Description: msgs.gateway
Content-Disposition: attachment; filename="msgs.gateway"

Sep 12 13:17:11 zel407 racoon: INFO: isakmp.c:891:isakmp_ph1begin_r(): respond n
ew phase 1 negotiation: 134.94.206.1[500]<=>134.94.206.11[500]
Sep 12 13:17:11 zel407 racoon: INFO: isakmp.c:896:isakmp_ph1begin_r(): begin Agg
ressive mode.
Sep 12 13:17:11 zel407 racoon: INFO: isakmp.c:2411:log_ph1established(): ISAKMP-
SA established 134.94.206.1[500]-134.94.206.11[500] spi:c0f47ce5791ad324:10ead06
db250a551
Sep 12 13:17:12 zel407 racoon: INFO: isakmp.c:1046:isakmp_ph2begin_r(): respond
new phase 2 negotiation: 134.94.206.1[0]<=>134.94.206.11[0]
Sep 12 13:17:12 zel407 racoon: INFO: pfkey.c:1107:pk_recvupdate(): IPsec-SA esta
blished: ESP/Tunnel 134.94.206.11->134.94.206.1 spi=207047846(0xc574ca6)
Sep 12 13:17:12 zel407 racoon: INFO: pfkey.c:1319:pk_recvadd(): IPsec-SA establi
shed: ESP/Tunnel 134.94.206.1->134.94.206.11 spi=111506327(0x6a57397)
Sep 12 13:17:13 zel407 racoon: INFO: isakmp.c:1046:isakmp_ph2begin_r(): respond
new phase 2 negotiation: 134.94.206.1[0]<=>134.94.206.11[0]
Sep 12 13:17:13 zel407 racoon: INFO: pfkey.c:1107:pk_recvupdate(): IPsec-SA esta
blished: ESP/Tunnel 134.94.206.11->134.94.206.1 spi=15371803(0xea8e1b)
Sep 12 13:17:13 zel407 racoon: INFO: pfkey.c:1319:pk_recvadd(): IPsec-SA establi
shed: ESP/Tunnel 134.94.206.1->134.94.206.11 spi=41368665(0x2773c59)

--==_Exmh_22412736133850
Content-Type: text/plain ; name="msgs.laptop"; charset=us-ascii
Content-Description: msgs.laptop
Content-Disposition: attachment; filename="msgs.laptop"

Sep 12 13:17:11 wlclient1 racoon: INFO: main.c:168:main(): @(#)package version n
etbsd-20020507
Sep 12 13:17:11 wlclient1 racoon: INFO: main.c:170:main(): @(#)internal version
20001216 sakane@kame.net
Sep 12 13:17:11 wlclient1 racoon: INFO: main.c:171:main(): @(#)This product link
ed OpenSSL 0.9.6g 9 Aug 2002 (http://www.openssl.org/)
Sep 12 13:17:11 wlclient1 racoon: INFO: isakmp.c:1357:isakmp_open(): 134.94.206.
11[500] used as isakmp port (fd=7)
Sep 12 13:17:11 wlclient1 racoon: INFO: isakmp.c:1357:isakmp_open(): fe80::207:e
bff:fe31:85a3%an0[500] used as isakmp port (fd=8)
Sep 12 13:17:11 wlclient1 racoon: INFO: isakmp.c:1357:isakmp_open(): fe80::1%lo0
[500] used as isakmp port (fd=9)
Sep 12 13:17:11 wlclient1 racoon: INFO: isakmp.c:1357:isakmp_open(): ::1[500] us
ed as isakmp port (fd=10)
Sep 12 13:17:11 wlclient1 racoon: INFO: isakmp.c:1357:isakmp_open(): 127.0.0.1[5
00] used as isakmp port (fd=11)
Sep 12 13:17:12 wlclient1 savecore: no core dump
Sep 12 13:17:12 wlclient1 racoon: INFO: isakmp.c:1683:isakmp_post_acquire(): IPs
ec-SA request for 134.94.206.1 queued due to no phase1 found.
Sep 12 13:17:12 wlclient1 racoon: INFO: isakmp.c:795:isakmp_ph1begin_i(): initia
te new phase 1 negotiation: 134.94.206.11[500]<=>134.94.206.1[500]
Sep 12 13:17:12 wlclient1 racoon: INFO: isakmp.c:800:isakmp_ph1begin_i(): begin
Aggressive mode.
Sep 12 13:17:13 wlclient1 racoon: INFO: vendorid.c:128:check_vendorid(): receive
d Vendor ID: KAME/racoon
Sep 12 13:17:13 wlclient1 racoon: INFO: isakmp.c:2411:log_ph1established(): ISAK
MP-SA established 134.94.206.11[500]-134.94.206.1[500] spi:c0f47ce5791ad324:10ea
d06db250a551
Sep 12 13:17:14 wlclient1 racoon: INFO: isakmp.c:939:isakmp_ph2begin_i(): initia
te new phase 2 negotiation: 134.94.206.11[0]<=>134.94.206.1[0]
Sep 12 13:17:14 wlclient1 racoon: INFO: pfkey.c:1107:pk_recvupdate(): IPsec-SA e
stablished: ESP/Tunnel 134.94.206.1->134.94.206.11 spi=111506327(0x6a57397)
Sep 12 13:17:14 wlclient1 racoon: INFO: pfkey.c:1319:pk_recvadd(): IPsec-SA esta
blished: ESP/Tunnel 134.94.206.11->134.94.206.1 spi=207047846(0xc574ca6)
Sep 12 13:17:13 wlclient1 ntpdate[131]: step time server 134.94.233.52 offset -2
.149232 sec
Sep 12 13:17:13 wlclient1 racoon: INFO: pfkey.c:1365:pk_recvexpire(): IPsec-SA e
xpired: ESP/Tunnel 134.94.206.11->134.94.206.1 spi=207047846(0xc574ca6)
Sep 12 13:17:13 wlclient1 racoon: INFO: isakmp.c:939:isakmp_ph2begin_i(): initia
te new phase 2 negotiation: 134.94.206.11[0]<=>134.94.206.1[0]
Sep 12 13:17:13 wlclient1 racoon: INFO: pfkey.c:1365:pk_recvexpire(): IPsec-SA e
xpired: ESP/Tunnel 134.94.206.1->134.94.206.11 spi=111506327(0x6a57397)
Sep 12 13:17:13 wlclient1 racoon: INFO: pfkey.c:1107:pk_recvupdate(): IPsec-SA e
stablished: ESP/Tunnel 134.94.206.1->134.94.206.11 spi=41368665(0x2773c59)
Sep 12 13:17:13 wlclient1 racoon: INFO: pfkey.c:1319:pk_recvadd(): IPsec-SA esta
blished: ESP/Tunnel 134.94.206.11->134.94.206.1 spi=15371803(0xea8e1b)
Sep 12 13:17:15 wlclient1 ntpd[193]: ntpd 4.0.99i Fri Aug  2 17:51:24 MEST 2002
(1)
Sep 12 13:17:15 wlclient1 ntpd[193]: precision = 6 usec
Sep 12 13:17:15 wlclient1 ntpd[193]: using kernel phase-lock loop 0040
Sep 12 13:17:15 wlclient1 ntpd[193]: frequency initialized 55.993 from /var/db/n
tp.drift
Sep 12 13:17:15 wlclient1 ntpd[193]: using kernel phase-lock loop 0041
Sep 12 13:17:34 wlclient1 /netbsd: IPv4 ESP input: no key association found for
spi 111506327
Sep 12 13:18:40 wlclient1 last message repeated 2 times

--==_Exmh_22412736133850--