updated copyright statement
[strongswan.git] / src / pluto / timer.c
1 /* timer event handling
2 * Copyright (C) 1997 Angelos D. Keromytis.
3 * Copyright (C) 1998-2001 D. Hugh Redelmeier.
4 * Copyright (C) 2009 Andreas Steffen - Hochschule fuer Technik Rapperswil
5 *
6 * This program is free software; you can redistribute it and/or modify it
7 * under the terms of the GNU General Public License as published by the
8 * Free Software Foundation; either version 2 of the License, or (at your
9 * option) any later version. See <http://www.fsf.org/copyleft/gpl.txt>.
10 *
11 * This program is distributed in the hope that it will be useful, but
12 * WITHOUT ANY WARRANTY; without even the implied warranty of MERCHANTABILITY
13 * or FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
14 * for more details.
15 */
16
17 #include <stdio.h>
18 #include <stdlib.h>
19 #include <sys/types.h>
20 #include <time.h>
21 #include <unistd.h>
22 #include <netinet/in.h>
23 #include <arpa/inet.h>
24 #include <sys/queue.h>
25
26 #include <freeswan.h>
27
28 #include <library.h>
29 #include <crypto/rngs/rng.h>
30
31 #include "constants.h"
32 #include "defs.h"
33 #include "connections.h"
34 #include "state.h"
35 #include "demux.h"
36 #include "ipsec_doi.h" /* needs demux.h and state.h */
37 #include "kernel.h"
38 #include "server.h"
39 #include "log.h"
40 #include "timer.h"
41 #include "whack.h"
42 #include "nat_traversal.h"
43
44 /**
45 * monotonic version of time(3)
46 */
47 time_t now(void)
48 {
49 static time_t delta = 0
50 , last_time = 0;
51 time_t n = time((time_t)NULL);
52
53 passert(n != (time_t)-1);
54 if (last_time > n)
55 {
56 plog("time moved backwards %ld seconds", (long)(last_time - n));
57 delta += last_time - n;
58 }
59 last_time = n;
60 return n + delta;
61 }
62
63 /* This file has the event handling routines. Events are
64 * kept as a linked list of event structures. These structures
65 * have information like event type, expiration time and a pointer
66 * to event specific data (for example, to a state structure).
67 */
68
69 static struct event *evlist = (struct event *) NULL;
70
71 /**
72 * This routine places an event in the event list.
73 */
74 void event_schedule(enum event_type type, time_t tm, struct state *st)
75 {
76 struct event *ev = malloc_thing(struct event);
77
78 ev->ev_type = type;
79 ev->ev_time = tm + now();
80 ev->ev_state = st;
81
82 /* If the event is associated with a state, put a backpointer to the
83 * event in the state object, so we can find and delete the event
84 * if we need to (for example, if we receive a reply).
85 */
86 if (st != NULL)
87 {
88 if (type == EVENT_DPD || type == EVENT_DPD_TIMEOUT)
89 {
90 passert(st->st_dpd_event == NULL);
91 st->st_dpd_event = ev;
92 }
93 else
94 {
95 passert(st->st_event == NULL);
96 st->st_event = ev;
97 }
98 }
99
100 DBG(DBG_CONTROL,
101 if (st == NULL)
102 DBG_log("inserting event %N, timeout in %lu seconds"
103 , timer_event_names, type, (unsigned long)tm);
104 else
105 DBG_log("inserting event %N, timeout in %lu seconds for #%lu"
106 , timer_event_names, type, (unsigned long)tm
107 , ev->ev_state->st_serialno));
108
109 if (evlist == (struct event *) NULL
110 || evlist->ev_time >= ev->ev_time)
111 {
112 ev->ev_next = evlist;
113 evlist = ev;
114 }
115 else
116 {
117 struct event *evt;
118
119 for (evt = evlist; evt->ev_next != NULL; evt = evt->ev_next)
120 if (evt->ev_next->ev_time >= ev->ev_time)
121 break;
122
123 #ifdef NEVER /* this seems to be overkill */
124 DBG(DBG_CONTROL,
125 if (evt->ev_state == NULL)
126 DBG_log("event added after event %N"
127 , timer_event_names, evt->ev_type);
128 else
129 DBG_log("event added after event %N for #%lu"
130 , timer_event_names, evt->ev_type,
131 , evt->ev_state->st_serialno));
132 #endif /* NEVER */
133
134 ev->ev_next = evt->ev_next;
135 evt->ev_next = ev;
136 }
137 }
138
139 /**
140 * Generate the secret value for responder cookies, and
141 * schedule an event for refresh.
142 */
143 void init_secret(void)
144 {
145 rng_t *rng;
146
147 rng = lib->crypto->create_rng(lib->crypto, RNG_STRONG);
148 rng->get_bytes(rng, sizeof(secret_of_the_day), secret_of_the_day);
149 rng->destroy(rng);
150 event_schedule(EVENT_REINIT_SECRET, EVENT_REINIT_SECRET_DELAY, NULL);
151 }
152
153 /**
154 * Handle the first event on the list.
155 */
156 void handle_timer_event(void)
157 {
158 time_t tm;
159 struct event *ev = evlist;
160 int type;
161 struct state *st;
162 struct connection *c = NULL;
163 ip_address peer;
164
165 if (ev == (struct event *) NULL) /* Just paranoid */
166 {
167 DBG(DBG_CONTROL, DBG_log("empty event list, yet we're called"));
168 return;
169 }
170
171 type = ev->ev_type;
172 st = ev->ev_state;
173
174 tm = now();
175
176 if (tm < ev->ev_time)
177 {
178 DBG(DBG_CONTROL, DBG_log("called while no event expired (%lu/%lu, %N)"
179 , (unsigned long)tm, (unsigned long)ev->ev_time
180 , timer_event_names, type));
181
182 /* This will happen if the most close-to-expire event was
183 * a retransmission or cleanup, and we received a packet
184 * at the same time as the event expired. Due to the processing
185 * order in call_server(), the packet processing will happen first,
186 * and the event will be removed.
187 */
188 return;
189 }
190
191 evlist = evlist->ev_next; /* Ok, we'll handle this event */
192
193 DBG(DBG_CONTROL,
194 if (evlist != (struct event *) NULL)
195 DBG_log("event after this is %N in %ld seconds"
196 , timer_event_names, evlist->ev_type
197 , (long) (evlist->ev_time - tm)));
198
199 /* for state-associated events, pick up the state pointer
200 * and remove the backpointer from the state object.
201 * We'll eventually either schedule a new event, or delete the state.
202 */
203 passert(GLOBALS_ARE_RESET());
204 if (st != NULL)
205 {
206 c = st->st_connection;
207 if (type == EVENT_DPD || type == EVENT_DPD_TIMEOUT)
208 {
209 passert(st->st_dpd_event == ev);
210 st->st_dpd_event = NULL;
211 }
212 else
213 {
214 passert(st->st_event == ev);
215 st->st_event = NULL;
216 }
217 peer = c->spd.that.host_addr;
218 set_cur_state(st);
219 }
220
221 switch (type)
222 {
223 case EVENT_REINIT_SECRET:
224 passert(st == NULL);
225 DBG(DBG_CONTROL, DBG_log("event EVENT_REINIT_SECRET handled"));
226 init_secret();
227 break;
228
229 #ifdef KLIPS
230 case EVENT_SHUNT_SCAN:
231 passert(st == NULL);
232 scan_proc_shunts();
233 break;
234 #endif
235
236 case EVENT_LOG_DAILY:
237 daily_log_event();
238 break;
239
240 case EVENT_RETRANSMIT:
241 /* Time to retransmit, or give up.
242 *
243 * Generally, we'll only try to send the message
244 * MAXIMUM_RETRANSMISSIONS times. Each time we double
245 * our patience.
246 *
247 * As a special case, if this is the first initiating message
248 * of a Main Mode exchange, and we have been directed to try
249 * forever, we'll extend the number of retransmissions to
250 * MAXIMUM_RETRANSMISSIONS_INITIAL times, with all these
251 * extended attempts having the same patience. The intention
252 * is to reduce the bother when nobody is home.
253 */
254 {
255 time_t delay = 0;
256
257 DBG(DBG_CONTROL, DBG_log(
258 "handling event EVENT_RETRANSMIT for %s \"%s\" #%lu"
259 , ip_str(&peer), c->name, st->st_serialno));
260
261 if (st->st_retransmit < MAXIMUM_RETRANSMISSIONS)
262 delay = EVENT_RETRANSMIT_DELAY_0 << (st->st_retransmit + 1);
263 else if (st->st_state == STATE_MAIN_I1
264 && c->sa_keying_tries == 0
265 && st->st_retransmit < MAXIMUM_RETRANSMISSIONS_INITIAL)
266 delay = EVENT_RETRANSMIT_DELAY_0 << MAXIMUM_RETRANSMISSIONS;
267
268 if (delay != 0)
269 {
270 st->st_retransmit++;
271 whack_log(RC_RETRANSMISSION
272 , "%s: retransmission; will wait %lus for response"
273 , enum_name(&state_names, st->st_state)
274 , (unsigned long)delay);
275 send_packet(st, "EVENT_RETRANSMIT");
276 event_schedule(EVENT_RETRANSMIT, delay, st);
277 }
278 else
279 {
280 /* check if we've tried rekeying enough times.
281 * st->st_try == 0 means that this should be the only try.
282 * c->sa_keying_tries == 0 means that there is no limit.
283 */
284 unsigned long try = st->st_try;
285 unsigned long try_limit = c->sa_keying_tries;
286 const char *details = "";
287
288 switch (st->st_state)
289 {
290 case STATE_MAIN_I3:
291 details = ". Possible authentication failure:"
292 " no acceptable response to our"
293 " first encrypted message";
294 break;
295 case STATE_MAIN_I1:
296 details = ". No response (or no acceptable response) to our"
297 " first IKE message";
298 break;
299 case STATE_QUICK_I1:
300 if (c->newest_ipsec_sa == SOS_NOBODY)
301 details = ". No acceptable response to our"
302 " first Quick Mode message:"
303 " perhaps peer likes no proposal";
304 break;
305 default:
306 break;
307 }
308 loglog(RC_NORETRANSMISSION
309 , "max number of retransmissions (%d) reached %s%s"
310 , st->st_retransmit
311 , enum_show(&state_names, st->st_state), details);
312 if (try != 0 && try != try_limit)
313 {
314 /* A lot like EVENT_SA_REPLACE, but over again.
315 * Since we know that st cannot be in use,
316 * we can delete it right away.
317 */
318 char story[80]; /* arbitrary limit */
319
320 try++;
321 snprintf(story, sizeof(story), try_limit == 0
322 ? "starting keying attempt %ld of an unlimited number"
323 : "starting keying attempt %ld of at most %ld"
324 , try, try_limit);
325
326 if (st->st_whack_sock != NULL_FD)
327 {
328 /* Release whack because the observer will get bored. */
329 loglog(RC_COMMENT, "%s, but releasing whack"
330 , story);
331 release_pending_whacks(st, story);
332 }
333 else
334 {
335 /* no whack: just log to syslog */
336 plog("%s", story);
337 }
338 ipsecdoi_replace(st, try);
339 }
340 delete_state(st);
341 }
342 }
343 break;
344
345 case EVENT_SA_REPLACE:
346 case EVENT_SA_REPLACE_IF_USED:
347 {
348 so_serial_t newest = IS_PHASE1(st->st_state)
349 ? c->newest_isakmp_sa : c->newest_ipsec_sa;
350
351 if (newest != st->st_serialno
352 && newest != SOS_NOBODY)
353 {
354 /* not very interesting: no need to replace */
355 DBG(DBG_LIFECYCLE
356 , plog("not replacing stale %s SA: #%lu will do"
357 , IS_PHASE1(st->st_state)? "ISAKMP" : "IPsec"
358 , newest));
359 }
360 else if (type == EVENT_SA_REPLACE_IF_USED
361 && st->st_outbound_time <= tm - c->sa_rekey_margin)
362 {
363 /* we observed no recent use: no need to replace
364 *
365 * The sampling effects mean that st_outbound_time
366 * could be up to SHUNT_SCAN_INTERVAL more recent
367 * than actual traffic because the sampler looks at change
368 * over that interval.
369 * st_outbound_time could also not yet reflect traffic
370 * in the last SHUNT_SCAN_INTERVAL.
371 * We expect that SHUNT_SCAN_INTERVAL is smaller than
372 * c->sa_rekey_margin so that the effects of this will
373 * be unimportant.
374 * This is just an optimization: correctness is not
375 * at stake.
376 *
377 * Note: we are abusing the DBG mechanism to control
378 * normal log output.
379 */
380 DBG(DBG_LIFECYCLE
381 , plog("not replacing stale %s SA: inactive for %lus"
382 , IS_PHASE1(st->st_state)? "ISAKMP" : "IPsec"
383 , (unsigned long)(tm - st->st_outbound_time)));
384 }
385 else
386 {
387 DBG(DBG_LIFECYCLE
388 , plog("replacing stale %s SA"
389 , IS_PHASE1(st->st_state)? "ISAKMP" : "IPsec"));
390 ipsecdoi_replace(st, 1);
391 }
392 delete_dpd_event(st);
393 event_schedule(EVENT_SA_EXPIRE, st->st_margin, st);
394 }
395 break;
396
397 case EVENT_SA_EXPIRE:
398 {
399 const char *satype;
400 so_serial_t latest;
401
402 if (IS_PHASE1(st->st_state))
403 {
404 satype = "ISAKMP";
405 latest = c->newest_isakmp_sa;
406 }
407 else
408 {
409 satype = "IPsec";
410 latest = c->newest_ipsec_sa;
411 }
412
413 if (st->st_serialno != latest)
414 {
415 /* not very interesting: already superseded */
416 DBG(DBG_LIFECYCLE
417 , plog("%s SA expired (superseded by #%lu)"
418 , satype, latest));
419 }
420 else
421 {
422 plog("%s SA expired (%s)", satype
423 , (c->policy & POLICY_DONT_REKEY)
424 ? "--dontrekey"
425 : "LATEST!"
426 );
427 }
428 }
429 /* FALLTHROUGH */
430 case EVENT_SO_DISCARD:
431 /* Delete this state object. It must be in the hash table. */
432 delete_state(st);
433 break;
434
435 case EVENT_DPD:
436 dpd_outI(st);
437 break;
438 case EVENT_DPD_TIMEOUT:
439 dpd_timeout(st);
440 break;
441 case EVENT_NAT_T_KEEPALIVE:
442 nat_traversal_ka_event();
443 break;
444 default:
445 loglog(RC_LOG_SERIOUS, "INTERNAL ERROR: ignoring unknown expiring event %N"
446 , timer_event_names, type);
447 }
448
449 free(ev);
450 reset_cur_state();
451 }
452
453 /**
454 * Return the time until the next event in the queue
455 * expires (never negative), or -1 if no jobs in queue.
456 */
457 long next_event(void)
458 {
459 time_t tm;
460
461 if (evlist == (struct event *) NULL)
462 return -1;
463
464 tm = now();
465
466 DBG(DBG_CONTROL,
467 if (evlist->ev_state == NULL)
468 DBG_log("next event %N in %ld seconds"
469 , timer_event_names, evlist->ev_type
470 , (long)evlist->ev_time - (long)tm);
471 else
472 DBG_log("next event %N in %ld seconds for #%lu"
473 , timer_event_names, evlist->ev_type
474 , (long)evlist->ev_time - (long)tm
475 , evlist->ev_state->st_serialno));
476
477 if (evlist->ev_time - tm <= 0)
478 return 0;
479 else
480 return evlist->ev_time - tm;
481 }
482
483 /**
484 * Delete an event.
485 */
486 void delete_event(struct state *st)
487 {
488 if (st->st_event != (struct event *) NULL)
489 {
490 struct event **ev;
491
492 for (ev = &evlist; ; ev = &(*ev)->ev_next)
493 {
494 if (*ev == NULL)
495 {
496 DBG(DBG_CONTROL, DBG_log("event %N to be deleted not found",
497 timer_event_names, st->st_event->ev_type));
498 break;
499 }
500 if ((*ev) == st->st_event)
501 {
502 *ev = (*ev)->ev_next;
503
504 if (st->st_event->ev_type == EVENT_RETRANSMIT)
505 {
506 st->st_retransmit = 0;
507 }
508 free(st->st_event);
509 st->st_event = (struct event *) NULL;
510
511 break;
512 }
513 }
514 }
515 }
516
517 /**
518 * Delete a DPD event.
519 */
520 void delete_dpd_event(struct state *st)
521 {
522 if (st->st_dpd_event != (struct event *) NULL)
523 {
524 struct event **ev;
525
526 for (ev = &evlist; ; ev = &(*ev)->ev_next)
527 {
528 if (*ev == NULL)
529 {
530 DBG(DBG_CONTROL, DBG_log("event %N to be deleted not found",
531 timer_event_names, st->st_dpd_event->ev_type));
532 break;
533 }
534 if ((*ev) == st->st_dpd_event)
535 {
536 *ev = (*ev)->ev_next;
537 free(st->st_dpd_event);
538 st->st_dpd_event = (struct event *) NULL;
539 break;
540 }
541 }
542 }
543 }
544
545 /**
546 * Free remaining events
547 */
548 void free_events(void)
549 {
550 struct event *ev_tmp, *ev;
551
552 ev = evlist;
553 evlist = NULL;
554
555 while (ev)
556 {
557 ev_tmp = ev;
558 ev = ev->ev_next;
559 free(ev_tmp);
560 }
561 }
562