Bug Summary

File:programs/pluto/timer.c
Warning:line 538, column 16
Access to field 'st_logger' results in a dereference of a null pointer (loaded from variable 'st')

Annotated Source Code

Press '?' to see keyboard shortcuts

clang -cc1 -triple x86_64-unknown-linux-gnu -analyze -disable-free -disable-llvm-verifier -discard-value-names -main-file-name timer.c -analyzer-store=region -analyzer-opt-analyze-nested-blocks -analyzer-checker=core -analyzer-checker=apiModeling -analyzer-checker=unix -analyzer-checker=deadcode -analyzer-checker=security.insecureAPI.UncheckedReturn -analyzer-checker=security.insecureAPI.getpw -analyzer-checker=security.insecureAPI.gets -analyzer-checker=security.insecureAPI.mktemp -analyzer-checker=security.insecureAPI.mkstemp -analyzer-checker=security.insecureAPI.vfork -analyzer-checker=nullability.NullPassedToNonnull -analyzer-checker=nullability.NullReturnedFromNonnull -analyzer-output plist -w -mrelocation-model pic -pic-level 2 -pic-is-pie -mthread-model posix -mdisable-fp-elim -relaxed-aliasing -fmath-errno -masm-verbose -mconstructor-aliases -munwind-tables -fuse-init-array -target-cpu x86-64 -dwarf-column-info -debugger-tuning=gdb -resource-dir /usr/lib64/clang/8.0.0 -D TimeZoneOffset=timezone -D linux -D PIE -D NSS_IPSEC_PROFILE -D XFRM_SUPPORT -D USE_XFRM_INTERFACE -D USE_DNSSEC -D DEFAULT_DNSSEC_ROOTKEY_FILE="/var/lib/unbound/root.key" -D HAVE_LABELED_IPSEC -D HAVE_SECCOMP -D LIBCURL -D USE_LINUX_AUDIT -D USE_SYSTEMD_WATCHDOG -D HAVE_NM -D XAUTH_HAVE_PAM -D USE_3DES -D USE_AES -D USE_CAMELLIA -D USE_CHACHA -D USE_DH31 -D USE_MD5 -D USE_SHA1 -D USE_SHA2 -D USE_PRF_AES_XCBC -D DEFAULT_RUNDIR="/run/pluto" -D IPSEC_CONF="/etc/ipsec.conf" -D IPSEC_CONFDDIR="/etc/ipsec.d" -D IPSEC_NSSDIR="/etc/ipsec.d" -D IPSEC_CONFDIR="/etc" -D IPSEC_EXECDIR="/usr/local/libexec/ipsec" -D IPSEC_SBINDIR="/usr/local/sbin" -D IPSEC_VARDIR="/var" -D POLICYGROUPSDIR="/etc/ipsec.d/policies" -D IPSEC_SECRETS_FILE="/etc/ipsec.secrets" -D FORCE_PR_ASSERT -D USE_FORK=1 -D USE_VFORK=0 -D USE_DAEMON=0 -D USE_PTHREAD_SETSCHEDPRIO=1 -D GCC_LINT -D HAVE_LIBCAP_NG -I . -I ../../OBJ.linux.x86_64/programs/pluto -I ../../include -I /usr/include/nss3 -I /usr/include/nspr4 -I /home/build/libreswan/programs/pluto/linux-copy -D HERE_BASENAME="timer.c" -internal-isystem /usr/local/include -internal-isystem /usr/lib64/clang/8.0.0/include -internal-externc-isystem /include -internal-externc-isystem /usr/include -Wno-missing-field-initializers -std=gnu99 -fdebug-compilation-dir /home/build/libreswan/programs/pluto -ferror-limit 19 -fmessage-length 0 -stack-protector 3 -fobjc-runtime=gcc -fdiagnostics-show-option -analyzer-output=html -o /tmp/scan-build-2020-09-09-193337-25440-1 -x c /home/build/libreswan/programs/pluto/timer.c -faddrsig
1/* timer event handling
2 *
3 * Copyright (C) 1997 Angelos D. Keromytis.
4 * Copyright (C) 1998-2001 D. Hugh Redelmeier.
5 * Copyright (C) 2005-2008 Michael Richardson <mcr@xelerance.com>
6 * Copyright (C) 2008-2010 Paul Wouters <paul@xelerance.com>
7 * Copyright (C) 2009 David McCullough <david_mccullough@securecomputing.com>
8 * Copyright (C) 2012 Avesh Agarwal <avagarwa@redhat.com>
9 * Copyright (C) 2012-2019 Paul Wouters <pwouters@redhat.com>
10 * Copyright (C) 2013 Matt Rogers <mrogers@redhat.com>
11 * Copyright (C) 2017 Antony Antony <antony@phenome.org>
12 * Copyright (C) 2017-2020 Andrew Cagney <cagney@gnu.org>
13 *
14 * This program is free software; you can redistribute it and/or modify it
15 * under the terms of the GNU General Public License as published by the
16 * Free Software Foundation; either version 2 of the License, or (at your
17 * option) any later version. See <https://www.gnu.org/licenses/gpl2.txt>.
18 *
19 * This program is distributed in the hope that it will be useful, but
20 * WITHOUT ANY WARRANTY; without even the implied warranty of MERCHANTABILITY
21 * or FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
22 * for more details.
23 */
24
25#include <stdio.h>
26#include <stdlib.h>
27#include <sys/types.h>
28#include <time.h>
29#include <unistd.h>
30#include <netinet/in.h>
31#include <arpa/inet.h>
32
33#include <event2/event.h>
34#include <event2/event_struct.h>
35
36#include "sysdep.h"
37#include "constants.h"
38#include "defs.h"
39#include "id.h"
40#include "x509.h"
41#include "certs.h"
42#include "connections.h" /* needs id.h */
43#include "state.h"
44#include "packet.h"
45#include "demux.h" /* needs packet.h */
46#include "ipsec_doi.h" /* needs demux.h and state.h */
47#include "kernel.h" /* needs connections.h */
48#include "server.h"
49#include "log.h"
50#include "rnd.h"
51#include "timer.h"
52#include "whack.h"
53#include "pluto_crypt.h" /* for pluto_crypto_req & pluto_crypto_req_cont */
54#include "ikev1_dpd.h"
55#include "ikev2.h"
56#include "ikev2_redirect.h"
57#include "pending.h" /* for flush_pending_by_connection */
58#include "ikev1_xauth.h"
59#include "xauth.h"
60#include "kernel.h" /* for kernel_ops */
61#include "nat_traversal.h"
62#include "pluto_sd.h"
63#include "retry.h"
64#include "fetch.h" /* for check_crls() */
65#include "pluto_stats.h"
66#include "iface.h"
67#include "ikev2_liveness.h"
68
69struct pluto_event **state_event(struct state *st, enum event_type type)
70{
71 /*
72 * Return a pointer to the event in the state object.
73 *
74 * XXX: why not just have an array and index it by KIND?
75 */
76 switch (type) {
77 case EVENT_v2_ADDR_CHANGE:
78 return &st->st_addr_change_event;
79 break;
80
81 case EVENT_DPD:
82 case EVENT_DPD_TIMEOUT:
83 return &st->st_dpd_event;
84
85 case EVENT_v2_LIVENESS:
86 return &st->st_liveness_event;
87
88 case EVENT_v2_RELEASE_WHACK:
89 return &st->st_rel_whack_event;
90
91 case EVENT_v1_SEND_XAUTH:
92 return &st->st_send_xauth_event;
93
94 case EVENT_RETRANSMIT:
95 return &st->st_retransmit_event;
96
97 case EVENT_SO_DISCARD:
98 case EVENT_SA_REKEY:
99 case EVENT_SA_REPLACE:
100 case EVENT_SA_EXPIRE:
101 case EVENT_v1_SA_REPLACE_IF_USED:
102 case EVENT_CRYPTO_TIMEOUT:
103 case EVENT_PAM_TIMEOUT:
104 case EVENT_v2_INITIATE_CHILD:
105 case EVENT_v2_REDIRECT:
106 /*
107 * Many of these don't make sense - however that's
108 * what happens when (the replaced) default: is used.
109 */
110 return &st->st_event;
111
112 case EVENT_RETAIN:
113 case EVENT_NULL:
114 return NULL((void*)0);
115 }
116 bad_case(type)libreswan_bad_case("type", (type), (where_t) { .func = __func__
, .basename = "timer.c" , .line = 116});
117}
118
119/*
120 * This file has the event handling routines. Events are
121 * kept as a linked list of event structures. These structures
122 * have information like event type, expiration time and a pointer
123 * to event specific data (for example, to a state structure).
124 */
125
126static event_callback_routine timer_event_cb;
127static void timer_event_cb(evutil_socket_tint unused_fd UNUSED__attribute__ ((unused)),
128 const short unused_event UNUSED__attribute__ ((unused)),
129 void *arg)
130{
131 threadtime_t inception = threadtime_start();
132
133 /*
134 * Get rid of the old timer event before calling the timer
135 * event processor (was deleting the old timer after calling
136 * the processor giving the impression that the processor's
137 * just created event was being deleted).
138 */
139 struct state *st;
140 enum event_type type;
141 const char *event_name;
142 {
143 struct pluto_event *ev = arg;
144 dbg("%s: processing event@%p", __func__, ev){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("%s: processing event@%p", __func__, ev); } };
145 passert(ev != NULL){ _Bool assertion__ = ev != ((void*)0); if (!assertion__) { lsw_passert_fail
((where_t) { .func = __func__, .basename = "timer.c" , .line =
145}, "%s", "ev != NULL"); } };
146 type = ev->ev_type;
147 event_name = enum_short_name(&timer_event_names, type);
148 st = ev->ev_state; /* note: *st might be changed; XXX: why? */
149 passert(st != NULL){ _Bool assertion__ = st != ((void*)0); if (!assertion__) { lsw_passert_fail
((where_t) { .func = __func__, .basename = "timer.c" , .line =
149}, "%s", "st != NULL"); } };
150
151 dbg("handling event %s for %s state #%lu",{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("handling event %s for %s state #%lu", enum_show
(&timer_event_names, type), (st->st_clonedfrom == 0) ?
"parent" : "child", st->st_serialno); } }
152 enum_show(&timer_event_names, type),{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("handling event %s for %s state #%lu", enum_show
(&timer_event_names, type), (st->st_clonedfrom == 0) ?
"parent" : "child", st->st_serialno); } }
153 (st->st_clonedfrom == SOS_NOBODY) ? "parent" : "child",{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("handling event %s for %s state #%lu", enum_show
(&timer_event_names, type), (st->st_clonedfrom == 0) ?
"parent" : "child", st->st_serialno); } }
154 st->st_serialno){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("handling event %s for %s state #%lu", enum_show
(&timer_event_names, type), (st->st_clonedfrom == 0) ?
"parent" : "child", st->st_serialno); } };
155
156#if 0
157 /*
158 * XXX: this line, which is a merger of the above two
159 * lines, leaks into the expected test output causing
160 * failures.
161 */
162 dbg("%s: processing %s-event@%p for %s SA #%lu in state %s",{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("%s: processing %s-event@%p for %s SA #%lu in state %s"
, __func__, event_name, ev, ((st)->st_clonedfrom == 0) ? "IKE"
: "CHILD", st->st_serialno, st->st_state->short_name
); } }
163 __func__, event_name, ev,{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("%s: processing %s-event@%p for %s SA #%lu in state %s"
, __func__, event_name, ev, ((st)->st_clonedfrom == 0) ? "IKE"
: "CHILD", st->st_serialno, st->st_state->short_name
); } }
164 IS_IKE_SA(st) ? "IKE" : "CHILD",{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("%s: processing %s-event@%p for %s SA #%lu in state %s"
, __func__, event_name, ev, ((st)->st_clonedfrom == 0) ? "IKE"
: "CHILD", st->st_serialno, st->st_state->short_name
); } }
165 st->st_serialno, st->st_state->short_name){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("%s: processing %s-event@%p for %s SA #%lu in state %s"
, __func__, event_name, ev, ((st)->st_clonedfrom == 0) ? "IKE"
: "CHILD", st->st_serialno, st->st_state->short_name
); } };
166#endif
167
168 struct pluto_event **evp = state_event(st, type);
169 if (evp == NULL((void*)0)) {
170 pexpect_fail(st->st_logger, HERE(where_t) { .func = __func__, .basename = "timer.c" , .line =
170},
171 "#%lu has no .st_event field for %s",
172 st->st_serialno, enum_name(&timer_event_names, type));
173 return;
174 }
175 if (*evp != ev) {
176 pexpect_fail(st->st_logger, HERE(where_t) { .func = __func__, .basename = "timer.c" , .line =
176},
177 "#%lu .st_event is %p but should be %s-pe@%p",
178 st->st_serialno, *evp,
179 enum_name(&timer_event_names, (*evp)->ev_type),
180 ev);
181 return;
182 }
183 delete_pluto_event(evp);
184 arg = ev = *evp = NULL((void*)0); /* all gone */
185 }
186
187 pexpect_reset_globals()log_pexpect_reset_globals((where_t) { .func = __func__, .basename
= "timer.c" , .line = 187});
188 so_serial_t old_state = push_cur_state(st)log_push_state(st, (where_t) { .func = __func__, .basename = "timer.c"
, .line = 188});
189 pexpect(old_state == SOS_NOBODY)({ _Bool assertion__ = old_state == 0; if (!assertion__) { log_pexpect
((where_t) { .func = __func__, .basename = "timer.c" , .line =
189}, "%s", "old_state == SOS_NOBODY"); } assertion__; }); /* since globals are reset */
190 statetime_t start = statetime_backdate(st, &inception);
191
192 /*
193 * Check that st is as expected for the event type.
194 *
195 * For an event type associated with a state, remove the
196 * backpointer from the appropriate slot of the state object.
197 *
198 * We'll eventually either schedule a new event, or delete the
199 * state.
200 */
201 switch (type) {
202
203 case EVENT_v2_ADDR_CHANGE:
204 dbg("#%lu IKEv2 local address change", st->st_serialno){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("#%lu IKEv2 local address change", st->st_serialno
); } };
205 ikev2_addr_change(st);
206 break;
207
208 case EVENT_v2_RELEASE_WHACK:
209 dbg("%s releasing whack for #%lu %s (sock="PRI_FD")",{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("%s releasing whack for #%lu %s (sock=""fd-fd@%p"
")", enum_show(&timer_event_names, type), st->st_serialno
, st->st_state->name, (st->st_logger->object_whackfd
)); } }
210 enum_show(&timer_event_names, type),{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("%s releasing whack for #%lu %s (sock=""fd-fd@%p"
")", enum_show(&timer_event_names, type), st->st_serialno
, st->st_state->name, (st->st_logger->object_whackfd
)); } }
211 st->st_serialno,{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("%s releasing whack for #%lu %s (sock=""fd-fd@%p"
")", enum_show(&timer_event_names, type), st->st_serialno
, st->st_state->name, (st->st_logger->object_whackfd
)); } }
212 st->st_state->name,{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("%s releasing whack for #%lu %s (sock=""fd-fd@%p"
")", enum_show(&timer_event_names, type), st->st_serialno
, st->st_state->name, (st->st_logger->object_whackfd
)); } }
213 pri_fd(st->st_whack_sock)){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("%s releasing whack for #%lu %s (sock=""fd-fd@%p"
")", enum_show(&timer_event_names, type), st->st_serialno
, st->st_state->name, (st->st_logger->object_whackfd
)); } };
214 release_pending_whacks(st, "release whack");
215 break;
216
217 case EVENT_RETRANSMIT:
218 dbg("IKEv%d retransmit event", st->st_ike_version){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("IKEv%d retransmit event", st->st_ike_version
); } };
219 switch (st->st_ike_version) {
220 case IKEv2:
221 retransmit_v2_msg(st);
222 break;
223 case IKEv1:
224 retransmit_v1_msg(st);
225 break;
226 default:
227 bad_case(st->st_ike_version)libreswan_bad_case("st->st_ike_version", (st->st_ike_version
), (where_t) { .func = __func__, .basename = "timer.c" , .line
= 227});
228 }
229 break;
230
231 case EVENT_v1_SEND_XAUTH:
232 dbg("XAUTH: event EVENT_v1_SEND_XAUTH #%lu %s",{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("XAUTH: event EVENT_v1_SEND_XAUTH #%lu %s", st
->st_serialno, st->st_state->name); } }
233 st->st_serialno, st->st_state->name){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("XAUTH: event EVENT_v1_SEND_XAUTH #%lu %s", st
->st_serialno, st->st_state->name); } };
234 xauth_send_request(st);
235 break;
236
237 case EVENT_v2_INITIATE_CHILD:
238 ikev2_child_outI(st);
239 break;
240
241 case EVENT_v2_LIVENESS:
242 liveness_check(st);
243 break;
244
245 case EVENT_SA_REKEY:
246 pexpect(st->st_ike_version == IKEv2)({ _Bool assertion__ = st->st_ike_version == IKEv2; if (!assertion__
) { log_pexpect((where_t) { .func = __func__, .basename = "timer.c"
, .line = 246}, "%s", "st->st_ike_version == IKEv2"); } assertion__
; });
247 v2_event_sa_rekey(st);
248 break;
249
250 case EVENT_SA_REPLACE:
251 case EVENT_v1_SA_REPLACE_IF_USED:
252 switch (st->st_ike_version) {
253 case IKEv2:
254 pexpect(type == EVENT_SA_REPLACE)({ _Bool assertion__ = type == EVENT_SA_REPLACE; if (!assertion__
) { log_pexpect((where_t) { .func = __func__, .basename = "timer.c"
, .line = 254}, "%s", "type == EVENT_SA_REPLACE"); } assertion__
; });
255 v2_event_sa_replace(st);
256 break;
257 case IKEv1:
258 pexpect(type == EVENT_SA_REPLACE ||({ _Bool assertion__ = type == EVENT_SA_REPLACE || type == EVENT_v1_SA_REPLACE_IF_USED
; if (!assertion__) { log_pexpect((where_t) { .func = __func__
, .basename = "timer.c" , .line = 259}, "%s", "type == EVENT_SA_REPLACE || type == EVENT_v1_SA_REPLACE_IF_USED"
); } assertion__; })
259 type == EVENT_v1_SA_REPLACE_IF_USED)({ _Bool assertion__ = type == EVENT_SA_REPLACE || type == EVENT_v1_SA_REPLACE_IF_USED
; if (!assertion__) { log_pexpect((where_t) { .func = __func__
, .basename = "timer.c" , .line = 259}, "%s", "type == EVENT_SA_REPLACE || type == EVENT_v1_SA_REPLACE_IF_USED"
); } assertion__; });
260 struct connection *c = st->st_connection;
261 const char *satype = IS_IKE_SA(st)((st)->st_clonedfrom == 0) ? "IKE" : "CHILD";
262
263 so_serial_t newer_sa = get_newer_sa_from_connection(st);
264 if (newer_sa != SOS_NOBODY0) {
265 /* not very interesting: no need to replace */
266 dbg("not replacing stale %s SA %lu; #%lu will do",{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("not replacing stale %s SA %lu; #%lu will do",
satype, st->st_serialno, newer_sa); } }
267 satype, st->st_serialno, newer_sa){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("not replacing stale %s SA %lu; #%lu will do",
satype, st->st_serialno, newer_sa); } };
268 } else if (type == EVENT_v1_SA_REPLACE_IF_USED &&
269 !monobefore(mononow(), monotime_add(st->st_outbound_time, c->sa_rekey_margin))) {
270 /*
271 * we observed no recent use: no need to replace
272 *
273 * The sampling effects mean that st_outbound_time
274 * could be up to SHUNT_SCAN_INTERVAL more recent
275 * than actual traffic because the sampler looks at
276 * change over that interval.
277 * st_outbound_time could also not yet reflect traffic
278 * in the last SHUNT_SCAN_INTERVAL.
279 * We expect that SHUNT_SCAN_INTERVAL is smaller than
280 * c->sa_rekey_margin so that the effects of this will
281 * be unimportant.
282 * This is just an optimization: correctness is not
283 * at stake.
284 */
285 dbg("not replacing stale %s SA: inactive for %jds",{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("not replacing stale %s SA: inactive for %jds"
, satype, deltasecs(monotimediff(mononow(), st->st_outbound_time
))); } }
286 satype, deltasecs(monotimediff(mononow(), st->st_outbound_time))){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("not replacing stale %s SA: inactive for %jds"
, satype, deltasecs(monotimediff(mononow(), st->st_outbound_time
))); } };
287 } else {
288 dbg("replacing stale %s SA",{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("replacing stale %s SA", ((st)->st_clonedfrom
== 0) ? "ISAKMP" : "IPsec"); } }
289 IS_IKE_SA(st) ? "ISAKMP" : "IPsec"){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("replacing stale %s SA", ((st)->st_clonedfrom
== 0) ? "ISAKMP" : "IPsec"); } };
290 /*
291 * XXX: this call gets double billed -
292 * both to the state being deleted and
293 * to the new state being created.
294 */
295 ipsecdoi_replace(st, 1);
296 }
297
298 event_delete(EVENT_v2_LIVENESS, st);
299 event_delete(EVENT_DPD, st);
300 event_schedule(EVENT_SA_EXPIRE, st->st_replace_margin, st);
301 break;
302 default:
303 bad_case(st->st_ike_version)libreswan_bad_case("st->st_ike_version", (st->st_ike_version
), (where_t) { .func = __func__, .basename = "timer.c" , .line
= 303});
304 }
305 break;
306
307 case EVENT_SA_EXPIRE:
308 {
309 struct connection *c = st->st_connection;
310 const char *satype = IS_IKE_SA(st)((st)->st_clonedfrom == 0) ? "IKE" : "CHILD";
311 so_serial_t newer_sa = get_newer_sa_from_connection(st);
312
313 if (newer_sa != SOS_NOBODY0) {
314 /* not very interesting: already superseded */
315 dbg("%s SA expired (superseded by #%lu)",{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("%s SA expired (superseded by #%lu)", satype, newer_sa
); } }
316 satype, newer_sa){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("%s SA expired (superseded by #%lu)", satype, newer_sa
); } };
317 } else if (!IS_IKE_SA_ESTABLISHED(st)( ((((lset_t)1 << ((st)->st_state->kind)) & (
((lset_t)1 << (STATE_MAIN_R3)) | ((lset_t)1 << (STATE_MAIN_I4
)) | ((lset_t)1 << (STATE_AGGR_I2)) | ((lset_t)1 <<
(STATE_AGGR_R2)) | ((lset_t)1 << (STATE_XAUTH_R0)) | (
(lset_t)1 << (STATE_XAUTH_R1)) | ((lset_t)1 << (STATE_MODE_CFG_R0
)) | ((lset_t)1 << (STATE_MODE_CFG_R1)) | ((lset_t)1 <<
(STATE_MODE_CFG_R2)) | ((lset_t)1 << (STATE_MODE_CFG_I1
)) | ((lset_t)1 << (STATE_XAUTH_I0)) | ((lset_t)1 <<
(STATE_XAUTH_I1)) | ((lset_t)1 << (STATE_V2_ESTABLISHED_IKE_SA
)))) != ((lset_t)0)) || ((((st)->st_state->kind == STATE_V2_ESTABLISHED_IKE_SA
) && !((st)->st_clonedfrom != 0)) && ((st)
->st_clonedfrom == 0)))) {
318 /* not very interesting: failed IKE attempt */
319 dbg("un-established partial CHILD SA timeout (%s)",{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("un-established partial CHILD SA timeout (%s)"
, type == EVENT_SA_EXPIRE ? "SA expired" : "Responder timeout"
); } }
320 type == EVENT_SA_EXPIRE ? "SA expired" : "Responder timeout"){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("un-established partial CHILD SA timeout (%s)"
, type == EVENT_SA_EXPIRE ? "SA expired" : "Responder timeout"
); } };
321 pstat_sa_failed(st, REASON_EXCHANGE_TIMEOUT);
322 } else {
323 libreswan_log("%s %s (%s)", satype,loglog(RC_LOG, "%s %s (%s)", satype, type == EVENT_SA_EXPIRE ?
"SA expired" : "Responder timeout", (c->policy & ((lset_t
)1 << (POLICY_DONT_REKEY_IX))) ? "--dontrekey" : "LATEST!"
)
324 type == EVENT_SA_EXPIRE ? "SA expired" : "Responder timeout",loglog(RC_LOG, "%s %s (%s)", satype, type == EVENT_SA_EXPIRE ?
"SA expired" : "Responder timeout", (c->policy & ((lset_t
)1 << (POLICY_DONT_REKEY_IX))) ? "--dontrekey" : "LATEST!"
)
325 (c->policy & POLICY_DONT_REKEY) ?loglog(RC_LOG, "%s %s (%s)", satype, type == EVENT_SA_EXPIRE ?
"SA expired" : "Responder timeout", (c->policy & ((lset_t
)1 << (POLICY_DONT_REKEY_IX))) ? "--dontrekey" : "LATEST!"
)
326 "--dontrekey" : "LATEST!")loglog(RC_LOG, "%s %s (%s)", satype, type == EVENT_SA_EXPIRE ?
"SA expired" : "Responder timeout", (c->policy & ((lset_t
)1 << (POLICY_DONT_REKEY_IX))) ? "--dontrekey" : "LATEST!"
);
327 }
328
329 /* Delete this state object. It must be in the hash table. */
330 switch (st->st_ike_version) {
331 case IKEv2:
332 if (IS_IKE_SA(st)((st)->st_clonedfrom == 0)) {
333 /* IKEv2 parent, delete children too */
334 delete_ike_family(pexpect_ike_sa(st),
335 PROBABLY_SEND_DELETE);
336 /* note: no md->st to clear */
337 } else {
338 struct ike_sa *ike = ike_sa(st, HERE(where_t) { .func = __func__, .basename = "timer.c" , .line =
338});
339 if (ike == NULL((void*)0)) {
340 /*
341 * XXX: SNAFU with IKE SA
342 * replacing itself (but not
343 * deleting its children?)
344 * simultaneous to a CHILD SA
345 * failing to establish and
346 * attempting to delete /
347 * replace itself?
348 *
349 * Because these things are
350 * not serialized it is hard
351 * to say.
352 */
353 loglog(RC_LOG_SERIOUS, "CHILD SA #%lu lost its IKE SA",
354 st->st_serialno);
355 delete_state(st);
356 st = NULL((void*)0);
357 } else {
358 /* note: no md->st to clear */
359 passert(st != &ike->sa){ _Bool assertion__ = st != &ike->sa; if (!assertion__
) { lsw_passert_fail((where_t) { .func = __func__, .basename =
"timer.c" , .line = 359}, "%s", "st != &ike->sa"); } };
360 schedule_next_child_delete(st, ike);
361 st = NULL((void*)0);
362 }
363 }
364 break;
365 case IKEv1:
366 delete_state(st);
367 /* note: no md->st to clear */
368 /* st = NULL; */
369 break;
370 default:
371 bad_case(st->st_ike_version)libreswan_bad_case("st->st_ike_version", (st->st_ike_version
), (where_t) { .func = __func__, .basename = "timer.c" , .line
= 371});
372 }
373 break;
374 }
375
376 case EVENT_SO_DISCARD:
377 /*
378 * The state failed to complete within a reasonable
379 * time, or the state failed but was left to live for
380 * a while so re-transmits could work. Either way,
381 * time to delete it.
382 */
383 passert(st != NULL){ _Bool assertion__ = st != ((void*)0); if (!assertion__) { lsw_passert_fail
((where_t) { .func = __func__, .basename = "timer.c" , .line =
383}, "%s", "st != NULL"); } };
384 deltatime_t timeout = (st->st_ike_version == IKEv2 ? MAXIMUM_RESPONDER_WAIT_DELAYdeltatime(200) :
385 st->st_connection->r_timeout);
386 deltatime_buf dtb;
387 libreswan_log("deleting incomplete state after %s seconds",loglog(RC_LOG, "deleting incomplete state after %s seconds", str_deltatime
(timeout, &dtb))
388 str_deltatime(timeout, &dtb))loglog(RC_LOG, "deleting incomplete state after %s seconds", str_deltatime
(timeout, &dtb));
389 /*
390 * If no other reason has been given then this is a
391 * timeout.
392 */
393 pstat_sa_failed(st, REASON_EXCHANGE_TIMEOUT);
394 /*
395 * XXX: this is scary overkill - delete_state() likes
396 * to resurect things and/or send messages. What's
397 * needed is a lower-level discard_state() that just
398 * does its job.
399 */
400 delete_state(st);
401 break;
402
403 case EVENT_v2_REDIRECT:
404 initiate_redirect(st);
405 break;
406
407 case EVENT_DPD:
408 dpd_event(st);
409 break;
410
411 case EVENT_DPD_TIMEOUT:
412 dpd_timeout(st);
413 break;
414
415 case EVENT_CRYPTO_TIMEOUT:
416 dbg("event crypto_failed on state #%lu, aborting",{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("event crypto_failed on state #%lu, aborting",
st->st_serialno); } }
417 st->st_serialno){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("event crypto_failed on state #%lu, aborting",
st->st_serialno); } };
418 pstat_sa_failed(st, REASON_CRYPTO_TIMEOUT);
419 delete_state(st);
420 /* note: no md->st to clear */
421 break;
422
423#ifdef XAUTH_HAVE_PAM1
424 case EVENT_PAM_TIMEOUT:
425 dbg("PAM thread timeout on state #%lu", st->st_serialno){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("PAM thread timeout on state #%lu", st->st_serialno
); } };
426 xauth_pam_abort(st);
427 /*
428 * Things get cleaned up when the PAM process exits.
429 *
430 * Should this schedule an event for the case when the
431 * child process (which is SIGKILLed) doesn't exit!?!
432 */
433 break;
434#endif
435
436 default:
437 bad_case(type)libreswan_bad_case("type", (type), (where_t) { .func = __func__
, .basename = "timer.c" , .line = 437});
438 }
439
440 statetime_stop(&start, "%s() %s", __func__, event_name);
441 pop_cur_state(old_state)log_pop_state(old_state, (where_t) { .func = __func__, .basename
= "timer.c" , .line = 441});
442}
443
444/*
445 * Delete all of the lifetime events (if any).
446 *
447 * Most lifetime events (things that kill the state) try to share a
448 * single .st_event. However, there has been and likely will be
449 * exceptions (for instance the retransmit timer), and the code below
450 * is written to deal with it.
451 *
452 * XXX:
453 *
454 * The decision to have all the loosely lifetime related timers
455 * (retransmit, rekey, replace, ...) share a single .st_event field is
456 * ... unfortunate. The code has to constantly juggle the field
457 * deciding which event is next. Far easier to set and forget each
458 * independently. This is why the retransmit timer has been split
459 * off.
460 */
461void delete_event(struct state *st)
462{
463 struct liveness {
464 const char *name;
465 struct pluto_event **event;
466 } events[] = {
467 { "st_event", &st->st_event, },
468 };
469 for (unsigned e = 0; e < elemsof(events)(sizeof(events) / sizeof(*(events))); e++) {
470 struct liveness *l = &events[e];
471 if (*(l->event) == NULL((void*)0)) {
472 dbg("state #%lu has no .%s to delete", st->st_serialno,{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("state #%lu has no .%s to delete", st->st_serialno
, l->name); } }
473 l->name){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("state #%lu has no .%s to delete", st->st_serialno
, l->name); } };
474 } else {
475 dbg("state #%lu deleting .%s %s",{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("state #%lu deleting .%s %s", st->st_serialno
, l->name, enum_show(&timer_event_names, (*l->event
)->ev_type)); } }
476 st->st_serialno, l->name,{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("state #%lu deleting .%s %s", st->st_serialno
, l->name, enum_show(&timer_event_names, (*l->event
)->ev_type)); } }
477 enum_show(&timer_event_names,{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("state #%lu deleting .%s %s", st->st_serialno
, l->name, enum_show(&timer_event_names, (*l->event
)->ev_type)); } }
478 (*l->event)->ev_type)){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("state #%lu deleting .%s %s", st->st_serialno
, l->name, enum_show(&timer_event_names, (*l->event
)->ev_type)); } };
479 delete_pluto_event(l->event);
480 }
481 }
482}
483
484/*
485 * This routine schedules a state event.
486 */
487void event_schedule(enum event_type type, deltatime_t delay, struct state *st)
488{
489 passert(st != NULL){ _Bool assertion__ = st != ((void*)0); if (!assertion__) { lsw_passert_fail
((where_t) { .func = __func__, .basename = "timer.c" , .line =
489}, "%s", "st != NULL"); } };
490 /*
491 * Scheduling a month into the future is most likely a bug.
492 * pexpect() causes us to flag this in our test cases
493 */
494 pexpect(deltasecs(delay) < secs_per_day * 31)({ _Bool assertion__ = deltasecs(delay) < secs_per_day * 31
; if (!assertion__) { log_pexpect((where_t) { .func = __func__
, .basename = "timer.c" , .line = 494}, "%s", "deltasecs(delay) < secs_per_day * 31"
); } assertion__; });
495
496 const char *en = enum_name(&timer_event_names, type);
497
498 struct pluto_event **evp = state_event(st, type);
499 if (evp == NULL((void*)0)) {
500 pexpect_fail(st->st_logger, HERE(where_t) { .func = __func__, .basename = "timer.c" , .line =
500},
501 "#%lu has no .st_*event field for %s",
502 st->st_serialno,
503 enum_name(&timer_event_names, type));
504 return;
505 }
506 if (*evp != NULL((void*)0)) {
507 /* help debugging by stumbling on */
508 pexpect_fail(st->st_logger, HERE(where_t) { .func = __func__, .basename = "timer.c" , .line =
508},
509 "#%lu already has a scheduled %s; forcing replacement",
510 st->st_serialno,
511 enum_name(&timer_event_names, type));
512 delete_pluto_event(evp);
513 }
514
515 struct pluto_event *ev = alloc_thing(struct pluto_event, en)((struct pluto_event*) alloc_bytes(sizeof(struct pluto_event)
, (en)));
516 dbg("%s: newref %s-pe@%p", __func__, en, ev){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("%s: newref %s-pe@%p", __func__, en, ev); } };
517 ev->ev_type = type;
518 ev->ev_name = en;
519 ev->ev_state = st;
520 ev->ev_time = monotime_add(mononow(), delay);
521 *evp = ev;
522
523 deltatime_buf buf;
524 dbg("inserting event %s, timeout in %s seconds for #%lu",{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("inserting event %s, timeout in %s seconds for #%lu"
, en, str_deltatime(delay, &buf), ev->ev_state->st_serialno
); } }
525 en, str_deltatime(delay, &buf),{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("inserting event %s, timeout in %s seconds for #%lu"
, en, str_deltatime(delay, &buf), ev->ev_state->st_serialno
); } }
526 ev->ev_state->st_serialno){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("inserting event %s, timeout in %s seconds for #%lu"
, en, str_deltatime(delay, &buf), ev->ev_state->st_serialno
); } };
527
528 fire_timer_photon_torpedo(&ev->ev, timer_event_cb, ev, delay);
529}
530
531/*
532 * Delete a state backlinked event (if any); leave *evp == NULL.
533 */
534void event_delete(enum event_type type, struct state *st)
535{
536 struct pluto_event **evp = state_event(st, type);
537 if (evp == NULL((void*)0)) {
3
←
Assuming 'evp' is equal to NULL
→
4
←
Taking true branch
→
538 pexpect_fail(st->st_logger, HERE(where_t) { .func = __func__, .basename = "timer.c" , .line =
538},
5
←
Access to field 'st_logger' results in a dereference of a null pointer (loaded from variable 'st')
539 "#%lu has no .st_event field for %s",
540 st->st_serialno, enum_name(&timer_event_names, type));
541 return;
542 }
543 if (*evp != NULL((void*)0)) {
544 dbg("#%lu requesting %s-pe@%p be deleted",{ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("#%lu requesting %s-pe@%p be deleted", st->
st_serialno, enum_name(&timer_event_names, (*evp)->ev_type
), *evp); } }
545 st->st_serialno, enum_name(&timer_event_names, (*evp)->ev_type), *evp){ if ((cur_debugging & (((lset_t)1 << (DBG_BASE_IX)
)))) { DBG_log("#%lu requesting %s-pe@%p be deleted", st->
st_serialno, enum_name(&timer_event_names, (*evp)->ev_type
), *evp); } };
546 pexpect(st == (*evp)->ev_state)({ _Bool assertion__ = st == (*evp)->ev_state; if (!assertion__
) { log_pexpect((where_t) { .func = __func__, .basename = "timer.c"
, .line = 546}, "%s", "st == (*evp)->ev_state"); } assertion__
; });
547 delete_pluto_event(evp);
548 pexpect((*evp) == NULL)({ _Bool assertion__ = (*evp) == ((void*)0); if (!assertion__
) { log_pexpect((where_t) { .func = __func__, .basename = "timer.c"
, .line = 548}, "%s", "(*evp) == NULL"); } assertion__; });
549 };
550}
551
552void event_force(enum event_type type, struct state *st)
553{
554 event_delete(type, st);
1
Passing value via 2nd parameter 'st'
→
2
←
Calling 'event_delete'
→
555 deltatime_t delay = deltatime(0);
556 event_schedule(type, delay, st);
557}
558
559void call_state_event_inline(struct logger *logger, struct state *st,
560 enum event_type event)
561{
562 /* sanity checks */
563 struct pluto_event **evp = state_event(st, event);
564 if (evp == NULL((void*)0)) {
565 log_message(RC_COMMENT, logger, "%s is not a valid event",
566 enum_name(&timer_event_names, event));
567 return;
568 }
569 if (*evp == NULL((void*)0)) {
570 log_message(RC_COMMENT, logger, "no handler for %s",
571 enum_name(&timer_event_names, event));
572 return;
573 }
574 if ((*evp)->ev_type != event) {
575 log_message(RC_COMMENT, logger, "handler for %s is actually %s",
576 enum_name(&timer_event_names, event),
577 enum_name(&timer_event_names, (*evp)->ev_type));
578 return;
579 }
580 /*
581 * XXX: can this kill off the old event when it is still
582 * pending?
583 */
584 log_message(RC_COMMENT, logger, "calling %s",
585 enum_name(&timer_event_names, event));
586 timer_event_cb(0/*sock*/, 0/*event*/, *evp);
587}