[Swan-dev] v1 delete behaviour continues with deleted state?

[Paul Wouters]

I see for IKEv1 that when we do an ispec auto --down westnet-eastnet
that:

- we send a delete for the phase2
- we send a delete for the phase1

The responder deletes it properly, however it seems to "continue"
processing when it has done the second delete that deletes the phase1:

"westnet-eastnet" #1: received Delete SA payload: deleting ISAKMP State #1
| deleting state #1
| **emit ISAKMP Message:

[...]

| sending 92 bytes for delete notify through eth1:500 to 192.1.2.45:500 (using #1)
|   5c 98 59 35  ae 7b d1 0c  84 67 2b 05  b7 0b d4 2a
|   08 10 05 01  9b a7 10 59  00 00 00 5c  93 d7 9c f3
|   a9 51 ab 36  7d 4c 07 d2  e3 d1 fe 8a  46 7c 2d 0b
|   86 1f b9 0b  92 60 a0 1d  fb 25 61 b3  b9 75 bf 09
|   36 dd ab 62  2f d3 10 3a  b7 ed 95 ee  0b 15 64 12
|   ba ce 88 c5  13 9c 51 f3  d8 b5 be f0
| deleting event for #1
| ICOOKIE:  5c 98 59 35  ae 7b d1 0c
| RCOOKIE:  84 67 2b 05  b7 0b d4 2a
| state hash entry 23
| unreference key: 0x7f8f0bc4db50 @west cnt 2--
| del:  5c 98 59 35  ae 7b d1 0c  84 67 2b 05  b7 0b d4 2a
packet from 192.1.2.45:500: received and ignored empty informational notification payload
| complete state transition with STF_IGNORE
| #140252354519104 complete_v1_state_transition:2184 st->st_calculating == FALSE;
| * processed 0 messages from cryptographic helpers
| next event EVENT_NAT_T_KEEPALIVE in 9 seconds
| next event EVENT_NAT_T_KEEPALIVE in 9 seconds

So the message "received and ignored empty informational" is a lie. We
processed a delete request.

We keep referencing a deleted state? Note state number is #140252354519104

This means one of these calls should not have happened:

ikev1.c:			DBG_log("#%lu %s:%u st->st_calculating == %s;",
ikev1_quick.c:	DBG(DBG_CONTROLMORE, DBG_log("#%lu %s:%u st->st_calculating == %s;", st->st_serialno, __FUNCTION__, __LINE__, st->st_calculating ? "TRUE" : "FALSE"));
state.c:	DBG(DBG_CONTROLMORE, DBG_log("#%lu %s:%u st->st_calculating == %s;", st->st_serialno, __FUNCTION__, __LINE__, st->st_calculating ? "TRUE" : "FALSE"));

Note that this is without electric fence.

These debug statements seem to go back to commit 7f1a4144 by Hugh

ommit 7f1a41440b5b1b54802550c5e840325c2e0e10d9
Author: D. Hugh Redelmeier <hugh at mimosa.com>
Date:   Mon Aug 11 21:47:51 2014 -0400

     ikev2: discard packets for a state that is busy (doing crypto or DNS)

     Add unset_suspend macro to catch more mistakes.


Note that the commit message talks about ikev2, while it edits files for
ikev1! Apparently classified as the second line of the commit message.

Paul