xref: /openbsd/usr.sbin/npppd/l2tp/l2tp_ctrl.c (revision cecf84d4)
1 /*	$OpenBSD: l2tp_ctrl.c,v 1.19 2015/01/19 01:48:59 deraadt Exp $	*/
2 
3 /*-
4  * Copyright (c) 2009 Internet Initiative Japan Inc.
5  * All rights reserved.
6  *
7  * Redistribution and use in source and binary forms, with or without
8  * modification, are permitted provided that the following conditions
9  * are met:
10  * 1. Redistributions of source code must retain the above copyright
11  *    notice, this list of conditions and the following disclaimer.
12  * 2. Redistributions in binary form must reproduce the above copyright
13  *    notice, this list of conditions and the following disclaimer in the
14  *    documentation and/or other materials provided with the distribution.
15  *
16  * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
17  * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
18  * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
19  * ARE DISCLAIMED.  IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE
20  * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
21  * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
22  * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
23  * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
24  * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
25  * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
26  * SUCH DAMAGE.
27  */
28 /**@file Control connection processing functions for L2TP LNS */
29 /* $Id: l2tp_ctrl.c,v 1.19 2015/01/19 01:48:59 deraadt Exp $ */
30 #include <sys/types.h>
31 #include <sys/time.h>
32 #include <sys/socket.h>
33 #include <netinet/in.h>
34 #include <net/if.h>
35 #include <arpa/inet.h>
36 #include <endian.h>
37 #include <errno.h>
38 #include <event.h>
39 #include <ifaddrs.h>
40 #include <netdb.h>
41 #include <stdarg.h>
42 #include <stddef.h>
43 #include <stdio.h>
44 #include <stdlib.h>
45 #include <string.h>
46 #include <syslog.h>
47 #include <time.h>
48 #include <unistd.h>
49 #include <limits.h>
50 
51 #ifdef USE_LIBSOCKUTIL
52 #include <seil/sockfromto.h>
53 #endif
54 
55 #include "time_utils.h"
56 #include "ipsec_util.h"
57 #include "bytebuf.h"
58 #include "hash.h"
59 #include "debugutil.h"
60 #include "slist.h"
61 #include "l2tp.h"
62 #include "l2tp_local.h"
63 #include "l2tp_subr.h"
64 #include "net_utils.h"
65 #include "version.h"
66 #include "recvfromto.h"
67 
68 #define MINIMUM(a, b)	(((a) < (b)) ? (a) : (b))
69 
70 static int                l2tp_ctrl_init (l2tp_ctrl *, l2tpd *, struct sockaddr *, struct sockaddr *, void *);
71 static void               l2tp_ctrl_reload (l2tp_ctrl *);
72 static int                l2tp_ctrl_send_disconnect_notify (l2tp_ctrl *);
73 #if 0
74 static void               l2tp_ctrl_purge_ipsec_sa (l2tp_ctrl *);
75 #endif
76 static void               l2tp_ctrl_timeout (int, short, void *);
77 static int                l2tp_ctrl_resend_una_packets (l2tp_ctrl *);
78 static void               l2tp_ctrl_destroy_all_calls (l2tp_ctrl *);
79 static int                l2tp_ctrl_disconnect_all_calls (l2tp_ctrl *);
80 static void               l2tp_ctrl_reset_timeout (l2tp_ctrl *);
81 static inline int         l2tp_ctrl_txwin_size (l2tp_ctrl *);
82 static inline int         l2tp_ctrl_txwin_is_full (l2tp_ctrl *);
83 static int                l2tp_ctrl_recv_SCCRQ (l2tp_ctrl *, u_char *, int, l2tpd *, struct sockaddr *);
84 static int                l2tp_ctrl_send_StopCCN (l2tp_ctrl *, int);
85 static int                l2tp_ctrl_recv_StopCCN (l2tp_ctrl *, u_char *, int);
86 static void               l2tp_ctrl_send_SCCRP (l2tp_ctrl *);
87 static int                l2tp_ctrl_send_HELLO (l2tp_ctrl *);
88 static int                l2tp_ctrl_send_ZLB (l2tp_ctrl *);
89 static inline const char  *l2tp_ctrl_state_string (l2tp_ctrl *);
90 
91 #ifdef	L2TP_CTRL_DEBUG
92 #define	L2TP_CTRL_ASSERT(x)	ASSERT(x)
93 #define	L2TP_CTRL_DBG(x)	l2tp_ctrl_log x
94 #else
95 #define	L2TP_CTRL_ASSERT(x)
96 #define	L2TP_CTRL_DBG(x)
97 #endif
98 
99 /* Sequence # of l2tp_ctrl ID */
100 static u_int l2tp_ctrl_id_seq = 0;
101 
102 #define SEQ_LT(a,b)	((int16_t)((a) - (b)) <  0)
103 #define SEQ_GT(a,b)	((int16_t)((a) - (b)) >  0)
104 
105 /**
106  * Build instance of {@link ::_l2tp_ctrl L2TP LNS control connection}
107  */
108 l2tp_ctrl *
109 l2tp_ctrl_create(void)
110 {
111 
112 	return calloc(1, sizeof(l2tp_ctrl));
113 }
114 
115 /**
116  * initialize and startup of {@link ::_l2tp_ctrl L2TP LNS control connection}
117  * instance
118  */
119 static int
120 l2tp_ctrl_init(l2tp_ctrl *_this, l2tpd *_l2tpd, struct sockaddr *peer,
121     struct sockaddr *sock, void *nat_t_ctx)
122 {
123 	int tunid, i;
124 	bytebuffer *bytebuf;
125 	time_t curr_time;
126 
127 	memset(_this, 0, sizeof(l2tp_ctrl));
128 
129 	curr_time = get_monosec();
130 	_this->l2tpd = _l2tpd;
131 	_this->state = L2TP_CTRL_STATE_IDLE;
132 	_this->last_snd_ctrl = curr_time;
133 
134 	slist_init(&_this->call_list);
135 
136 	/* seek a free tunnel ID */
137 	i = 0;
138 	_this->id = ++l2tp_ctrl_id_seq;
139 	for (i = 0, tunid = _this->id; ; i++, tunid++) {
140 		tunid &= 0xffff;
141 		_this->tunnel_id = l2tp_ctrl_id_seq & 0xffff;
142 		if (tunid == 0)
143 			continue;
144 		if (l2tpd_get_ctrl(_l2tpd, tunid) == NULL)
145 			break;
146 		if (i > 80000) {
147 			/* this must be happen, just log it. */
148 			l2tpd_log(_l2tpd, LOG_ERR, "Too many l2tp controls");
149 			return -1;
150 		}
151 	}
152 
153 	_this->tunnel_id = tunid;
154 
155 	L2TP_CTRL_ASSERT(peer != NULL);
156 	L2TP_CTRL_ASSERT(sock != NULL);
157 	memcpy(&_this->peer, peer, peer->sa_len);
158 	memcpy(&_this->sock, sock, sock->sa_len);
159 
160 	/* prepare send buffer */
161 	_this->winsz = L2TPD_DEFAULT_SEND_WINSZ;
162 	if ((_this->snd_buffers = calloc(_this->winsz, sizeof(bytebuffer *)))
163 	    == NULL) {
164 		l2tpd_log(_l2tpd, LOG_ERR,
165 		    "calloc() failed in %s(): %m", __func__);
166 		goto fail;
167 	}
168 	for (i = 0; i < _this->winsz; i++) {
169 		if ((bytebuf = bytebuffer_create(L2TPD_SND_BUFSIZ)) == NULL) {
170 			l2tpd_log(_l2tpd, LOG_ERR,
171 			    "bytebuffer_create() failed in %s(): %m", __func__);
172 			goto fail;
173 		}
174 		_this->snd_buffers[i] = bytebuf;
175 	}
176 	if ((_this->zlb_buffer = bytebuffer_create(sizeof(struct l2tp_header)
177 	    + 128)) == NULL) {
178 		l2tpd_log(_l2tpd, LOG_ERR,
179 		    "bytebuffer_create() failed in %s(): %m", __func__);
180 		goto fail;
181 	}
182 #if defined(USE_LIBSOCKUTIL) || defined(USE_SA_COOKIE)
183 	if (nat_t_ctx != NULL) {
184 		if ((_this->sa_cookie = malloc(
185 		    sizeof(struct in_ipsec_sa_cookie))) != NULL) {
186 			*(struct in_ipsec_sa_cookie *)_this->sa_cookie =
187 			    *(struct in_ipsec_sa_cookie *)nat_t_ctx;
188 		} else {
189 			l2tpd_log(_l2tpd, LOG_ERR,
190 			    "creating sa_cookie failed: %m");
191 			goto fail;
192 		}
193 	}
194 #endif
195 	_this->hello_interval = L2TP_CTRL_DEFAULT_HELLO_INTERVAL;
196 	_this->hello_timeout = L2TP_CTRL_DEFAULT_HELLO_TIMEOUT;
197 	_this->hello_io_time = curr_time;
198 
199 	/* initialize timeout timer */
200 	l2tp_ctrl_reset_timeout(_this);
201 
202 	/* register l2tp context */
203 	l2tpd_add_ctrl(_l2tpd, _this);
204 	return 0;
205 fail:
206 	l2tp_ctrl_stop(_this, 0);
207 	return -1;
208 }
209 
210 /*
211  * setup {@link ::_l2tp_ctrl L2TP LNS control connection} instance
212  */
213 static void
214 l2tp_ctrl_reload(l2tp_ctrl *_this)
215 {
216 	_this->data_use_seq = L2TP_CTRL_CONF(_this)->data_use_seq;
217 	if (L2TP_CTRL_CONF(_this)->hello_interval != 0)
218 		_this->hello_interval =  L2TP_CTRL_CONF(_this)->hello_interval;
219 	if (L2TP_CTRL_CONF(_this)->hello_timeout != 0)
220 		_this->hello_timeout = L2TP_CTRL_CONF(_this)->hello_timeout;
221 }
222 
223 /*
224  * free {@link ::_l2tp_ctrl L2TP LNS control connection} instance
225  */
226 void
227 l2tp_ctrl_destroy(l2tp_ctrl *_this)
228 {
229 	L2TP_CTRL_ASSERT(_this != NULL);
230 #if defined(USE_LIBSOCKUTIL) || defined(USE_SA_COOKIE)
231 	if (_this->sa_cookie != NULL)
232 		free(_this->sa_cookie);
233 #endif
234 	free(_this);
235 }
236 
237 /*
238  * nortify disconnection to peer
239  *
240  * @return 	0: all CDN and StopCCN have been sent.
241  *		N: if the remaining calls which still not sent CDN exist,
242  *		   return # of the calls.
243  *		-1: when try to send of StopCCN failed.
244  */
245 static int
246 l2tp_ctrl_send_disconnect_notify(l2tp_ctrl *_this)
247 {
248 	int ncalls;
249 
250 	L2TP_CTRL_ASSERT(_this != NULL)
251 	L2TP_CTRL_ASSERT(_this->state == L2TP_CTRL_STATE_ESTABLISHED ||
252 	    _this->state == L2TP_CTRL_STATE_CLEANUP_WAIT);
253 
254 	/* this control is not actively closing or StopCCN have been sent */
255 	if (_this->active_closing == 0)
256 		return 0;
257 
258 	/* Send CDN all Calls */
259 	ncalls = 0;
260 	if (slist_length(&_this->call_list) != 0) {
261 		ncalls = l2tp_ctrl_disconnect_all_calls(_this);
262 		if (ncalls > 0) {
263 			/*
264 			 * Call the function again to check whether the
265 			 * sending window is fulled.  In case ncalls == 0,
266 			 * it means we've sent CDN for all calls.
267 			 */
268 			ncalls = l2tp_ctrl_disconnect_all_calls(_this);
269 		}
270 	}
271 	if (ncalls > 0)
272 		return ncalls;
273 
274 	if (l2tp_ctrl_send_StopCCN(_this, _this->active_closing) != 0)
275 		return -1;
276 	_this->active_closing = 0;
277 
278 	return 0;
279 }
280 
281 /*
282  * Terminate the control connection
283  *
284  * <p>
285  * please specify an appropriate value to result( >0 ) for
286  * StopCCN ResultCode AVP, when to sent Active Close (which
287  * require StopCCN sent).</p>
288  * <p>
289  * When the return value of this function is zero, the _this
290  * is already released. The lt2p_ctrl process that was bound to it
291  * could not contine.
292  * When the return value of this function is one, the timer
293  * is reset.</p>
294  *
295  * @return	return 0 if terminate process was completed.
296  */
297 int
298 l2tp_ctrl_stop(l2tp_ctrl *_this, int result)
299 {
300 	int i;
301 	l2tpd *_l2tpd;
302 
303 	L2TP_CTRL_ASSERT(_this != NULL);
304 
305 	switch (_this->state) {
306 	case L2TP_CTRL_STATE_ESTABLISHED:
307 		_this->state = L2TP_CTRL_STATE_CLEANUP_WAIT;
308 		if (result > 0) {
309 			_this->active_closing = result;
310 			l2tp_ctrl_send_disconnect_notify(_this);
311 			break;
312 		}
313 		goto cleanup;
314 	default:
315 		l2tp_ctrl_log(_this, LOG_DEBUG, "%s() unexpected state=%s",
316 		    __func__, l2tp_ctrl_state_string(_this));
317 		/* FALLTHROUGH */
318 	case L2TP_CTRL_STATE_WAIT_CTL_CONN:
319 		/* FALLTHROUGH */
320 	case L2TP_CTRL_STATE_CLEANUP_WAIT:
321 cleanup:
322 		if (slist_length(&_this->call_list) != 0) {
323 			if (l2tp_ctrl_disconnect_all_calls(_this) > 0)
324 				break;
325 		}
326 #if 0
327 		if (L2TP_CTRL_CONF(_this)e_ipsec_sa != 0)
328 			l2tp_ctrl_purge_ipsec_sa(_this);
329 #endif
330 
331 		l2tp_ctrl_log(_this, LOG_NOTICE, "logtype=Finished");
332 
333 		evtimer_del(&_this->ev_timeout);
334 
335 		/* free send buffer */
336 		if (_this->snd_buffers != NULL) {
337 			for (i = 0; i < _this->winsz; i++)
338 				bytebuffer_destroy(_this->snd_buffers[i]);
339 			free(_this->snd_buffers);
340 			_this->snd_buffers = NULL;
341 		}
342 		if (_this->zlb_buffer != NULL) {
343 			bytebuffer_destroy(_this->zlb_buffer);
344 			_this->zlb_buffer = NULL;
345 		}
346 
347 		/* free l2tp_call */
348 		l2tp_ctrl_destroy_all_calls(_this);
349 		slist_fini(&_this->call_list);
350 
351 		l2tpd_remove_ctrl(_this->l2tpd, _this->tunnel_id);
352 
353 		_l2tpd = _this->l2tpd;
354 		l2tp_ctrl_destroy(_this);
355 
356 		l2tpd_ctrl_finished_notify(_l2tpd);
357 		return 0;	/* stopped */
358 	}
359 	l2tp_ctrl_reset_timeout(_this);
360 
361 	return 1;
362 }
363 
364 #if 0
365 /** Delete the IPsec SA for disconnection */
366 static void
367 l2tp_ctrl_purge_ipsec_sa(l2tp_ctrl *_this)
368 {
369 	int is_natt, proto;
370 	struct sockaddr_storage peer, sock;
371 	hash_link *hl;
372 #ifdef USE_LIBSOCKUTIL
373 	struct in_ipsec_sa_cookie *ipsec_sa_cookie;
374 #endif
375 	l2tp_ctrl *anot;
376 
377 	/*
378 	 * Search another tunnel that uses the same IPsec SA
379 	 * by lineer.
380 	 */
381 	for (hl = hash_first(_this->l2tpd->ctrl_map);
382 	    hl != NULL; hl = hash_next(_this->l2tpd->ctrl_map)) {
383 		anot = hl->item;
384 		if (anot == _this)
385 			continue;
386 
387 		if (_this->peer.ss_family != anot->peer.ss_family)
388 			continue;
389 		if (_this->peer.ss_family == AF_INET) {
390 			if (SIN(&_this->peer)->sin_addr.s_addr !=
391 			    SIN(&anot->peer)->sin_addr.s_addr)
392 				continue;
393 		} else if (_this->peer.ss_family == AF_INET6) {
394 			if (!IN6_ARE_ADDR_EQUAL(
395 			    &(SIN6(&_this->peer)->sin6_addr),
396 			    &(SIN6(&anot->peer)->sin6_addr)))
397 				continue;
398 		}
399 #ifdef USE_LIBSOCKUTIL
400 		if (_this->sa_cookie != NULL && anot->sa_cookie != NULL) {
401 			/* Both tunnels belong the same NAT box.  */
402 
403 			if (memcmp(_this->sa_cookie, anot->sa_cookie,
404 			    sizeof(struct in_ipsec_sa_cookie)) != 0)
405 				/* Different hosts behind the NAT box.  */
406 				continue;
407 
408 			/* The SA is shared by another tunnels by one host. */
409 			return;	/* don't purge the sa */
410 
411 		} else if (_this->sa_cookie != NULL || anot->sa_cookie != NULL)
412 			/* Only one is behind the NAT */
413 			continue;
414 #endif
415 		return;	/* don't purge the sa */
416 	}
417 
418 #if defined(USE_LIBSOCKUTIL)  && defined(IP_IPSEC_SA_COOKIE)
419 	is_natt = (_this->sa_cookie != NULL)? 1 : 0;
420 #else
421 	is_natt = 0;
422 #endif
423 	proto = 0;
424 	memcpy(&peer, &_this->peer, _this->peer.ss_len);
425 	memcpy(&sock, &_this->sock, _this->sock.ss_len);
426 	if (!is_natt)
427 		SIN(&peer)->sin_port = SIN(&sock)->sin_port = 0;
428 #if defined(USE_LIBSOCKUTIL)  && defined(IP_IPSEC_SA_COOKIE)
429 	else {
430 		ipsec_sa_cookie = _this->sa_cookie;
431 		SIN(&peer)->sin_port = ipsec_sa_cookie->remote_port;
432 		SIN(&sock)->sin_port = ipsec_sa_cookie->local_port;
433 #if 1
434 		/*
435 		 * XXX: As RFC 2367, protocol sould be specified if the port
436 		 * XXX: number is non-zero.
437 		 */
438 		proto = 0;
439 #else
440 		proto = IPPROTO_UDP;
441 #endif
442 	}
443 #endif
444 	if (ipsec_util_purge_transport_sa((struct sockaddr *)&peer,
445 	    (struct sockaddr *)&sock, proto, IPSEC_UTIL_DIRECTION_BOTH) != 0)
446 		l2tp_ctrl_log(_this, LOG_NOTICE, "failed to purge IPSec SA");
447 }
448 #endif
449 
450 /* timeout processing */
451 static void
452 l2tp_ctrl_timeout(int fd, short evtype, void *ctx)
453 {
454 	int next_timeout, need_resend;
455 	time_t curr_time;
456 	l2tp_ctrl *_this;
457 	l2tp_call *call;
458 
459 	/*
460 	 * the timer must be reset, when leave this function.
461 	 * MEMO: l2tp_ctrl_stop() will reset the timer in it.
462 	 * and please remember that the l2tp_ctrl_stop() may free _this.
463 	 */
464 	_this = ctx;
465 	L2TP_CTRL_ASSERT(_this != NULL);
466 
467 	curr_time = get_monosec();
468 
469 	next_timeout = 2;
470 	need_resend = 0;
471 
472 	if (l2tp_ctrl_txwin_size(_this) > 0)  {
473 		if (_this->state == L2TP_CTRL_STATE_ESTABLISHED) {
474 			if (_this->hello_wait_ack != 0) {
475 				/* wait Hello reply */
476 				if (curr_time - _this->hello_io_time >=
477 				    _this->hello_timeout) {
478 					l2tp_ctrl_log(_this, LOG_NOTICE,
479 					    "timeout waiting ack for hello "
480 					    "packets.");
481 					l2tp_ctrl_stop(_this,
482 					    L2TP_STOP_CCN_RCODE_GENERAL);
483 					return;
484 				}
485 			}
486 		} else if (curr_time - _this->last_snd_ctrl >=
487 		    L2TP_CTRL_CTRL_PKT_TIMEOUT) {
488 			l2tp_ctrl_log(_this, LOG_NOTICE,
489 			    "timeout waiting ack for ctrl packets.");
490 			l2tp_ctrl_stop(_this,
491 			    L2TP_STOP_CCN_RCODE_GENERAL);
492 			return;
493 		}
494 		need_resend = 1;
495 	} else {
496 		for (slist_itr_first(&_this->call_list);
497 		    slist_itr_has_next(&_this->call_list);) {
498 			call = slist_itr_next(&_this->call_list);
499 			if (call->state == L2TP_CALL_STATE_CLEANUP_WAIT) {
500 				l2tp_call_destroy(call, 1);
501 				slist_itr_remove(&_this->call_list);
502 			}
503 		}
504 	}
505 
506 	switch (_this->state) {
507 	case L2TP_CTRL_STATE_IDLE:
508 		/*
509 		 * idle:
510 		 * XXX: never happen in current implementation
511 		 */
512 		l2tp_ctrl_log(_this, LOG_ERR,
513 		    "Internal error, timeout on illegal state=idle");
514 		l2tp_ctrl_stop(_this, L2TP_STOP_CCN_RCODE_GENERAL);
515 		break;
516 	case L2TP_CTRL_STATE_WAIT_CTL_CONN:
517 		/*
518 		 * wait-ctrl-conn:
519 		 * 	if there is no ack for SCCRP, the peer will
520 		 * 	resend SCCRQ. however this implementation can
521 		 *	not recognize that the SCCRQ was resent or not.
522 		 *	Therefore, never resent from this side.
523 		 */
524 		need_resend = 0;
525 		break;
526 	case L2TP_CTRL_STATE_ESTABLISHED:
527 		if (slist_length(&_this->call_list) == 0 &&
528 		    curr_time - _this->last_snd_ctrl >=
529 			    L2TP_CTRL_WAIT_CALL_TIMEOUT) {
530 			if (_this->ncalls == 0)
531 				/* fail to receive first call */
532 				l2tp_ctrl_log(_this, LOG_WARNING,
533 				    "timeout waiting call");
534 			l2tp_ctrl_stop(_this,
535 			    L2TP_STOP_CCN_RCODE_GENERAL);
536 			return;
537 		}
538 		if (_this->hello_wait_ack == 0 && _this->hello_interval > 0) {
539 			/* send Hello */
540 			if (curr_time - _this->hello_interval >=
541 			    _this->hello_io_time) {
542 				if (l2tp_ctrl_send_HELLO(_this) == 0)
543 					/* success */
544 					_this->hello_wait_ack = 1;
545 				_this->hello_io_time = curr_time;
546 				need_resend = 0;
547 			}
548 		}
549 		break;
550 	case L2TP_CTRL_STATE_CLEANUP_WAIT:
551 		if (curr_time - _this->last_snd_ctrl >=
552 		    L2TP_CTRL_CLEANUP_WAIT_TIME) {
553 			l2tp_ctrl_log(_this, LOG_NOTICE,
554 			    "Cleanup timeout state=%d", _this->state);
555 			l2tp_ctrl_stop(_this, 0);
556 			return;
557 		}
558 		if (_this->active_closing != 0)
559 			l2tp_ctrl_send_disconnect_notify(_this);
560 		break;
561 	default:
562 		l2tp_ctrl_log(_this, LOG_ERR,
563 		    "Internal error, timeout on illegal state=%d",
564 			_this->state);
565 		l2tp_ctrl_stop(_this, L2TP_STOP_CCN_RCODE_GENERAL);
566 		return;
567 	}
568 	/* resend if required */
569 	if (need_resend)
570 		l2tp_ctrl_resend_una_packets(_this);
571 	l2tp_ctrl_reset_timeout(_this);
572 }
573 
574 int
575 l2tp_ctrl_send(l2tp_ctrl *_this, const void *msg, int len)
576 {
577 	int rval;
578 
579 #ifdef USE_LIBSOCKUTIL
580 	if (_this->sa_cookie != NULL)
581 		rval = sendfromto_nat_t(LISTENER_SOCK(_this), msg, len, 0,
582 		    (struct sockaddr *)&_this->sock,
583 		    (struct sockaddr *)&_this->peer, _this->sa_cookie);
584 	else
585 		rval = sendfromto(LISTENER_SOCK(_this), msg, len, 0,
586 		    (struct sockaddr *)&_this->sock,
587 		    (struct sockaddr *)&_this->peer);
588 #else
589 #ifdef USE_SA_COOKIE
590 	if (_this->sa_cookie != NULL)
591 		rval = sendto_nat_t(LISTENER_SOCK(_this), msg, len, 0,
592 		    (struct sockaddr *)&_this->peer, _this->peer.ss_len,
593 		    _this->sa_cookie);
594 	else
595 #endif
596 	rval = sendto(LISTENER_SOCK(_this), msg, len, 0,
597 	    (struct sockaddr *)&_this->peer, _this->peer.ss_len);
598 #endif
599 	return rval;
600 }
601 
602 /* resend una packets */
603 static int
604 l2tp_ctrl_resend_una_packets(l2tp_ctrl *_this)
605 {
606 	uint16_t seq;
607 	bytebuffer *bytebuf;
608 	struct l2tp_header *header;
609 	int nsend;
610 
611 	nsend = 0;
612 	for (seq = _this->snd_una; SEQ_LT(seq, _this->snd_nxt); seq++) {
613 		bytebuf = _this->snd_buffers[seq % _this->winsz];
614 		header = bytebuffer_pointer(bytebuf);
615 		header->nr = htons(_this->rcv_nxt);
616 #ifdef L2TP_CTRL_DEBUG
617 		if (debuglevel >= 3) {
618 			l2tp_ctrl_log(_this, DEBUG_LEVEL_3, "RESEND seq=%u",
619 			    ntohs(header->ns));
620 			show_hd(debug_get_debugfp(),
621 			    bytebuffer_pointer(bytebuf),
622 			    bytebuffer_remaining(bytebuf));
623 		}
624 #endif
625 		if (l2tp_ctrl_send(_this, bytebuffer_pointer(bytebuf),
626 		    bytebuffer_remaining(bytebuf)) < 0) {
627 			l2tp_ctrl_log(_this, LOG_ERR,
628 			    "sendto() failed in %s: %m", __func__);
629 			return -1;
630 		}
631 		nsend++;
632 	}
633 	return nsend;
634 }
635 
636 /* free all calls */
637 static void
638 l2tp_ctrl_destroy_all_calls(l2tp_ctrl *_this)
639 {
640 	l2tp_call *call;
641 
642 	L2TP_CTRL_ASSERT(_this != NULL);
643 
644 	while ((call = slist_remove_first(&_this->call_list)) != NULL)
645 		l2tp_call_destroy(call, 1);
646 }
647 
648 
649 /* disconnect all calls on the control context
650  * @return return # of calls that is not waiting cleanup.
651  */
652 static int
653 l2tp_ctrl_disconnect_all_calls(l2tp_ctrl *_this)
654 {
655 	int i, len, ncalls;
656 	l2tp_call *call;
657 
658 	L2TP_CTRL_ASSERT(_this != NULL);
659 
660 	ncalls = 0;
661 	len = slist_length(&_this->call_list);
662 	for (i = 0; i < len; i++) {
663 		call = slist_get(&_this->call_list, i);
664 		if (call->state != L2TP_CALL_STATE_CLEANUP_WAIT) {
665 			ncalls++;
666 
667 			if (l2tp_ctrl_txwin_is_full(_this)) {
668 				L2TP_CTRL_DBG((_this, LOG_INFO,
669 				    "Too many calls.  Sending window is not "
670 				    "enough to send CDN to all clients."));
671 				/* nothing to do */
672 			} else
673 				l2tp_call_admin_disconnect(call);
674 		}
675 	}
676 	return ncalls;
677 }
678 
679 /* reset timeout */
680 static void
681 l2tp_ctrl_reset_timeout(l2tp_ctrl *_this)
682 {
683 	int intvl;
684 	struct timeval tv0;
685 
686 	L2TP_CTRL_ASSERT(_this != NULL);
687 
688 	if (evtimer_initialized(&_this->ev_timeout))
689 		evtimer_del(&_this->ev_timeout);
690 
691 	switch (_this->state) {
692 	case L2TP_CTRL_STATE_CLEANUP_WAIT:
693 		intvl = 1;
694 		break;
695 	default:
696 		intvl = 2;
697 		break;
698 	}
699 	tv0.tv_usec = 0;
700 	tv0.tv_sec = intvl;
701 	if (!evtimer_initialized(&_this->ev_timeout))
702 		evtimer_set(&_this->ev_timeout, l2tp_ctrl_timeout, _this);
703 	evtimer_add(&_this->ev_timeout, &tv0);
704 }
705 
706 /*
707  * protocols / send and receive
708  */
709 /* Receive packet */
710 void
711 l2tp_ctrl_input(l2tpd *_this, int listener_index, struct sockaddr *peer,
712     struct sockaddr *sock, void *nat_t_ctx, u_char *pkt, int pktlen)
713 {
714 	int i, len, offsiz, reqlen, is_ctrl;
715 	uint16_t mestype;
716 	struct l2tp_avp *avp, *avp0;
717 	l2tp_ctrl *ctrl;
718 	l2tp_call *call;
719 	char buf[L2TP_AVP_MAXSIZ], errmsg[256];
720 	time_t curr_time;
721 	u_char *pkt0;
722 	struct l2tp_header hdr;
723 	char hbuf[NI_MAXHOST + NI_MAXSERV + 16];
724 
725 	ctrl = NULL;
726 	curr_time = get_monosec();
727 	pkt0 = pkt;
728 
729 	L2TP_CTRL_ASSERT(peer->sa_family == sock->sa_family);
730 	L2TP_CTRL_ASSERT(peer->sa_family == AF_INET ||
731 	    peer->sa_family == AF_INET6)
732     /*
733      * Parse L2TP Header
734      */
735 	memset(&hdr, 0, sizeof(hdr));
736 	if (pktlen < 2) {
737 		snprintf(errmsg, sizeof(errmsg), "a short packet.  "
738 		    "length=%d", pktlen);
739 		goto bad_packet;
740 	}
741 	memcpy(&hdr, pkt, 2);
742 	pkt += 2;
743 	if (hdr.ver != L2TP_HEADER_VERSION_RFC2661) {
744 		/* XXX: only RFC2661 is supported */
745 		snprintf(errmsg, sizeof(errmsg),
746 		    "Unsupported version at header = %d", hdr.ver);
747 		goto bad_packet;
748 	}
749 	is_ctrl = (hdr.t != 0)? 1 : 0;
750 
751 	/* calc required length */
752 	reqlen = 6;		/* for Flags, Tunnel-Id, Session-Id field */
753 	if (hdr.l) reqlen += 2;	/* for Length field (opt) */
754 	if (hdr.s) reqlen += 4;	/* for Ns, Nr field (opt) */
755 	if (hdr.o) reqlen += 2;	/* for Offset Size field (opt) */
756 	if (reqlen > pktlen) {
757 		snprintf(errmsg, sizeof(errmsg),
758 		    "a short packet. length=%d", pktlen);
759 		goto bad_packet;
760 	}
761 
762 	if (hdr.l != 0) {
763 		GETSHORT(hdr.length, pkt);
764 		if (hdr.length > pktlen) {
765 			snprintf(errmsg, sizeof(errmsg),
766 			    "Actual packet size is smaller than the length "
767 			    "field %d < %d", pktlen, hdr.length);
768 			goto bad_packet;
769 		}
770 		pktlen = hdr.length;	/* remove trailing trash */
771 	}
772 	GETSHORT(hdr.tunnel_id, pkt);
773 	GETSHORT(hdr.session_id, pkt);
774 	if (hdr.s != 0) {
775 		GETSHORT(hdr.ns, pkt);
776 		GETSHORT(hdr.nr, pkt);
777 	}
778 	if (hdr.o != 0) {
779 		GETSHORT(offsiz, pkt);
780 		if (pktlen < offsiz) {
781 			snprintf(errmsg, sizeof(errmsg),
782 			    "offset field is bigger than remaining packet "
783 			    "length %d > %d", offsiz, pktlen);
784 			goto bad_packet;
785 		}
786 		pkt += offsiz;
787 	}
788 	L2TP_CTRL_ASSERT(pkt - pkt0 == reqlen);
789 	pktlen -= (pkt - pkt0);	/* cut down the length of header */
790 
791 	ctrl = NULL;
792 	memset(buf, 0, sizeof(buf));
793 	mestype = 0;
794 	avp = NULL;
795 
796 	if (is_ctrl) {
797 		avp0 = (struct l2tp_avp *)buf;
798 		avp = avp_find_message_type_avp(avp0, pkt, pktlen);
799 		if (avp != NULL)
800 			mestype = avp->attr_value[0] << 8 | avp->attr_value[1];
801 	}
802 	ctrl = l2tpd_get_ctrl(_this, hdr.tunnel_id);
803 
804 	if (ctrl == NULL) {
805 		/* new control */
806 		if (!is_ctrl) {
807 			snprintf(errmsg, sizeof(errmsg),
808 			    "bad data message: tunnelId=%d is not "
809 			    "found.", hdr.tunnel_id);
810 			goto bad_packet;
811 		}
812 		if (mestype != L2TP_AVP_MESSAGE_TYPE_SCCRQ) {
813 			snprintf(errmsg, sizeof(errmsg),
814 			    "bad control message: tunnelId=%d is not "
815 			    "found.  mestype=%s", hdr.tunnel_id,
816 			    avp_mes_type_string(mestype));
817 			goto bad_packet;
818 		}
819 
820 		if ((ctrl = l2tp_ctrl_create()) == NULL) {
821 			l2tp_ctrl_log(ctrl, LOG_ERR,
822 			    "l2tp_ctrl_create() failed: %m");
823 			goto fail;
824 		}
825 
826 		if (l2tp_ctrl_init(ctrl, _this, peer, sock, nat_t_ctx) != 0) {
827 			l2tp_ctrl_log(ctrl, LOG_ERR,
828 			    "l2tp_ctrl_start() failed: %m");
829 			goto fail;
830 		}
831 
832 		ctrl->listener_index = listener_index;
833 		l2tp_ctrl_reload(ctrl);
834 	} else {
835 		/*
836 		 * treat as an error if src address and port is not
837 		 * match. (because it is potentially DoS attach)
838 		 */
839 		int notmatch = 0;
840 
841 		if (ctrl->peer.ss_family != peer->sa_family)
842 			notmatch = 1;
843 		else if (peer->sa_family == AF_INET) {
844 			if (SIN(peer)->sin_addr.s_addr !=
845 			    SIN(&ctrl->peer)->sin_addr.s_addr ||
846 			    SIN(peer)->sin_port != SIN(&ctrl->peer)->sin_port)
847 				notmatch = 1;
848 		} else if (peer->sa_family == AF_INET6) {
849 			if (!IN6_ARE_ADDR_EQUAL(&(SIN6(peer)->sin6_addr),
850 				    &(SIN6(&ctrl->peer)->sin6_addr)) ||
851 			    SIN6(peer)->sin6_port !=
852 				    SIN6(&ctrl->peer)->sin6_port)
853 				notmatch = 1;
854  		}
855 		if (notmatch) {
856 			snprintf(errmsg, sizeof(errmsg),
857 			    "tunnelId=%u is already assigned for %s",
858 			    hdr.tunnel_id, addrport_tostring(
859 				(struct sockaddr *)&ctrl->peer,
860 				ctrl->peer.ss_len, hbuf, sizeof(hbuf)));
861 			goto bad_packet;
862 		}
863 	}
864 	ctrl->last_rcv = curr_time;
865 	call = NULL;
866 	if (hdr.session_id != 0) {
867 		/* search l2tp_call by Session ID */
868 		/* linear search is enough for this purpose */
869 		len = slist_length(&ctrl->call_list);
870 		for (i = 0; i < len; i++) {
871 			call = slist_get(&ctrl->call_list, i);
872 			if (call->session_id == hdr.session_id)
873 				break;
874 			call = NULL;
875 		}
876 	}
877 	if (!is_ctrl) {
878 		int delayed = 0;
879 
880 		/* L2TP data */
881 		if (ctrl->state != L2TP_CTRL_STATE_ESTABLISHED) {
882 			l2tp_ctrl_log(ctrl, LOG_WARNING,
883 			    "Received Data packet in '%s'",
884 			    l2tp_ctrl_state_string(ctrl));
885 			goto fail;
886 		}
887 		if (call == NULL) {
888 			l2tp_ctrl_log(ctrl, LOG_WARNING,
889 			    "Received a data packet but it has no call.  "
890 			    "session_id=%u",  hdr.session_id);
891 			goto fail;
892 		}
893 		L2TP_CTRL_DBG((ctrl, DEBUG_LEVEL_2,
894 		    "call=%u RECV   ns=%u nr=%u snd_nxt=%u rcv_nxt=%u len=%d",
895 		    call->id, hdr.ns, hdr.nr, call->snd_nxt, call->rcv_nxt,
896 		    pktlen));
897 		if (call->state != L2TP_CALL_STATE_ESTABLISHED){
898 			l2tp_ctrl_log(ctrl, LOG_WARNING,
899 			    "Received a data packet but call is not "
900 			    "established");
901 			goto fail;
902 		}
903 
904 		if (hdr.s != 0) {
905 			if (SEQ_LT(hdr.ns, call->rcv_nxt)) {
906 				if (SEQ_LT(hdr.ns,
907 				    call->rcv_nxt - L2TP_CALL_DELAY_LIMIT)) {
908 					/* sequence number seems to be delayed */
909 					/* XXX: need to log? */
910 					L2TP_CTRL_DBG((ctrl, LOG_DEBUG,
911 					    "receive a out of sequence "
912 					    "data packet: %u < %u.",
913 					    hdr.ns, call->rcv_nxt));
914 					return;
915 				}
916 				delayed = 1;
917 			} else {
918 				call->rcv_nxt = hdr.ns + 1;
919 			}
920 		}
921 
922 		l2tp_call_ppp_input(call, pkt, pktlen, delayed);
923 
924 		return;
925 	}
926 	if (hdr.s != 0) {
927 		L2TP_CTRL_DBG((ctrl, DEBUG_LEVEL_2,
928 		    "RECV %s ns=%u nr=%u snd_nxt=%u snd_una=%u rcv_nxt=%u "
929 		    "len=%d", (is_ctrl)? "C" : "", hdr.ns, hdr.nr,
930 		    ctrl->snd_nxt, ctrl->snd_una, ctrl->rcv_nxt, pktlen));
931 
932 		if (pktlen <= 0)
933 			l2tp_ctrl_log(ctrl, LOG_INFO, "RecvZLB");
934 
935 		if (SEQ_GT(hdr.nr, ctrl->snd_una)) {
936 			if (hdr.nr == ctrl->snd_nxt ||
937 			    SEQ_LT(hdr.nr, ctrl->snd_nxt))
938 				ctrl->snd_una = hdr.nr;
939 			else {
940 				l2tp_ctrl_log(ctrl, LOG_INFO,
941 				    "Received message has bad Nr field: "
942 				    "%u < %u.", hdr.ns, ctrl->snd_nxt);
943 				/* XXX Drop with ZLB? */
944 				goto fail;
945 			}
946 		}
947 		if (l2tp_ctrl_txwin_size(ctrl) <= 0) {
948 			/* no waiting ack */
949 			if (ctrl->hello_wait_ack != 0) {
950 				/*
951 				 * Reset Hello state, as an ack for the Hello
952 				 * is recived.
953 				 */
954 				ctrl->hello_wait_ack = 0;
955 				ctrl->hello_io_time = curr_time;
956 			}
957 			switch (ctrl->state) {
958 			case L2TP_CTRL_STATE_CLEANUP_WAIT:
959 				l2tp_ctrl_stop(ctrl, 0);
960 				return;
961 			}
962 		}
963 		if (hdr.ns != ctrl->rcv_nxt) {
964 			/* there are remaining packet */
965 			if (l2tp_ctrl_resend_una_packets(ctrl) <= 0) {
966 				/* resend or sent ZLB */
967 				l2tp_ctrl_send_ZLB(ctrl);
968 			}
969 #ifdef	L2TP_CTRL_DEBUG
970 			if (pktlen != 0) {	/* not ZLB */
971 				L2TP_CTRL_DBG((ctrl, LOG_DEBUG,
972 				    "receive out of sequence %u must be %u.  "
973 				    "mestype=%s", hdr.ns, ctrl->rcv_nxt,
974 				    avp_mes_type_string(mestype)));
975 			}
976 #endif
977 			return;
978 		}
979 		if (pktlen <= 0)
980 			return;		/* ZLB */
981 
982 		if (l2tp_ctrl_txwin_is_full(ctrl)) {
983 			L2TP_CTRL_DBG((ctrl, LOG_DEBUG,
984 			    "Received message cannot be handled. "
985 			    "Transmission window is full."));
986 			l2tp_ctrl_send_ZLB(ctrl);
987 			return;
988 		}
989 
990 		ctrl->rcv_nxt++;
991 		if (avp == NULL) {
992 			l2tpd_log(_this, LOG_WARNING,
993 			    "bad control message: no message-type AVP.");
994 			goto fail;
995 		}
996 	}
997 
998     /*
999      * state machine (RFC2661 pp. 56-57)
1000      */
1001 	switch (ctrl->state) {
1002 	case L2TP_CTRL_STATE_IDLE:
1003 		switch (mestype) {
1004 		case L2TP_AVP_MESSAGE_TYPE_SCCRQ:
1005 			if (l2tp_ctrl_recv_SCCRQ(ctrl, pkt, pktlen, _this,
1006 			    peer) == 0) {
1007 				/* acceptable */
1008 				l2tp_ctrl_send_SCCRP(ctrl);
1009 				ctrl->state = L2TP_CTRL_STATE_WAIT_CTL_CONN;
1010 				return;
1011 			}
1012 			/*
1013 			 * in case un-acceptable, it was already processed
1014 			 * at l2tcp_ctrl_recv_SCCRQ
1015 			 */
1016 			return;
1017 		case L2TP_AVP_MESSAGE_TYPE_SCCRP:
1018 			/*
1019 			 * RFC specifies that sent of StopCCN in the state,
1020 			 * However as this implementation only support Passive
1021 			 * open, this packet will not received.
1022 			 */
1023 			/* FALLTHROUGH */
1024 		case L2TP_AVP_MESSAGE_TYPE_SCCCN:
1025 		default:
1026 			break;
1027 		}
1028 		goto fsm_fail;
1029 
1030 	case L2TP_CTRL_STATE_WAIT_CTL_CONN:
1031 	    /* Wait-Ctl-Conn */
1032 		switch (mestype) {
1033 		case L2TP_AVP_MESSAGE_TYPE_SCCCN:
1034 			l2tp_ctrl_log(ctrl, LOG_INFO, "RecvSCCN");
1035 			if (l2tp_ctrl_send_ZLB(ctrl) == 0) {
1036 				ctrl->state = L2TP_CTRL_STATE_ESTABLISHED;
1037 			}
1038 			return;
1039 		case L2TP_AVP_MESSAGE_TYPE_StopCCN:
1040 			goto receive_stop_ccn;
1041 		case L2TP_AVP_MESSAGE_TYPE_SCCRQ:
1042 		case L2TP_AVP_MESSAGE_TYPE_SCCRP:
1043 		default:
1044 			break;
1045 		}
1046 		break;	/* fsm_fail */
1047 	case L2TP_CTRL_STATE_ESTABLISHED:
1048 	    /* Established */
1049 		switch (mestype) {
1050 		case L2TP_AVP_MESSAGE_TYPE_SCCCN:
1051 		case L2TP_AVP_MESSAGE_TYPE_SCCRQ:
1052 		case L2TP_AVP_MESSAGE_TYPE_SCCRP:
1053 			break;
1054 receive_stop_ccn:
1055 		case L2TP_AVP_MESSAGE_TYPE_StopCCN:
1056 			if (l2tp_ctrl_recv_StopCCN(ctrl, pkt, pktlen) == 0) {
1057 				if (l2tp_ctrl_resend_una_packets(ctrl) <= 0)
1058 					l2tp_ctrl_send_ZLB(ctrl);
1059 				l2tp_ctrl_stop(ctrl, 0);
1060 				return;
1061 			}
1062 			l2tp_ctrl_log(ctrl, LOG_ERR, "Received bad StopCCN");
1063 			l2tp_ctrl_send_ZLB(ctrl);
1064 			l2tp_ctrl_stop(ctrl, 0);
1065 			return;
1066 
1067 		case L2TP_AVP_MESSAGE_TYPE_HELLO:
1068 			if (l2tp_ctrl_resend_una_packets(ctrl) <= 0)
1069 				l2tp_ctrl_send_ZLB(ctrl);
1070 			return;
1071 		case L2TP_AVP_MESSAGE_TYPE_CDN:
1072 		case L2TP_AVP_MESSAGE_TYPE_ICRP:
1073 		case L2TP_AVP_MESSAGE_TYPE_ICCN:
1074 			if (call == NULL) {
1075 				l2tp_ctrl_log(ctrl, LOG_INFO,
1076 				    "Unknown call message: %s",
1077 				    avp_mes_type_string(mestype));
1078 				goto fail;
1079 			}
1080 			/* FALLTHROUGH */
1081 		case L2TP_AVP_MESSAGE_TYPE_ICRQ:
1082 			l2tp_call_recv_packet(ctrl, call, mestype, pkt,
1083 			    pktlen);
1084 			return;
1085 		default:
1086 			break;
1087 		}
1088 		break;	/* fsm_fail */
1089 	case L2TP_CTRL_STATE_CLEANUP_WAIT:
1090 		if (mestype == L2TP_AVP_MESSAGE_TYPE_StopCCN) {
1091 			/*
1092 			 * We left ESTABLISHED state, but the peer sent StopCCN.
1093 			 */
1094 			goto receive_stop_ccn;
1095 		}
1096 		break;	/* fsm_fail */
1097 	}
1098 
1099 fsm_fail:
1100 	/* state machine error */
1101 	l2tp_ctrl_log(ctrl, LOG_WARNING, "Received %s in '%s' state",
1102 	    avp_mes_type_string(mestype), l2tp_ctrl_state_string(ctrl));
1103 	l2tp_ctrl_stop(ctrl, L2TP_STOP_CCN_RCODE_FSM_ERROR);
1104 
1105 	return;
1106 fail:
1107 	if (ctrl != NULL && mestype != 0) {
1108 		l2tp_ctrl_log(ctrl, LOG_WARNING, "Received %s in '%s' state",
1109 		    avp_mes_type_string(mestype), l2tp_ctrl_state_string(ctrl));
1110 		l2tp_ctrl_stop(ctrl, L2TP_STOP_CCN_RCODE_GENERAL_ERROR);
1111 	}
1112 	return;
1113 
1114 bad_packet:
1115 	l2tpd_log(_this, LOG_INFO, "Received from=%s: %s",
1116 	    addrport_tostring(peer, peer->sa_len, hbuf, sizeof(hbuf)), errmsg);
1117 
1118 	return;
1119 }
1120 
1121 static inline int
1122 l2tp_ctrl_txwin_size(l2tp_ctrl *_this)
1123 {
1124 	uint16_t sz;
1125 
1126 	sz = _this->snd_nxt - _this->snd_una;
1127 
1128 	L2TP_CTRL_ASSERT(sz <= _this->winsz);
1129 
1130 	return sz;
1131 }
1132 
1133 static inline int
1134 l2tp_ctrl_txwin_is_full(l2tp_ctrl *_this)
1135 {
1136 	return (l2tp_ctrl_txwin_size(_this) >= _this->winsz)? 1 : 0;
1137 }
1138 
1139 /* send control packet */
1140 int
1141 l2tp_ctrl_send_packet(l2tp_ctrl *_this, int call_id, bytebuffer *bytebuf)
1142 {
1143 	struct l2tp_header *hdr;
1144 	int rval;
1145 	time_t curr_time;
1146 
1147 	curr_time = get_monosec();
1148 
1149 	bytebuffer_flip(bytebuf);
1150 	hdr = (struct l2tp_header *)bytebuffer_pointer(bytebuf);
1151 	memset(hdr, 0, sizeof(*hdr));
1152 
1153 	hdr->t = 1;
1154 	hdr->ver = L2TP_HEADER_VERSION_RFC2661;
1155 	hdr->l = 1;
1156 	hdr->length = htons(bytebuffer_remaining(bytebuf));
1157 	hdr->tunnel_id = htons(_this->peer_tunnel_id);
1158 	hdr->session_id = htons(call_id);
1159 
1160 	hdr->s = 1;
1161 	hdr->ns = htons(_this->snd_nxt);
1162 	hdr->nr = htons(_this->rcv_nxt);
1163 
1164 	if (bytebuffer_remaining(bytebuf) > sizeof(struct l2tp_header))
1165 		/* Not ZLB */
1166 		_this->snd_nxt++;
1167 
1168 	L2TP_CTRL_DBG((_this, DEBUG_LEVEL_2,
1169 	    "SEND C ns=%u nr=%u snd_nxt=%u snd_una=%u rcv_nxt=%u ",
1170 	    ntohs(hdr->ns), htons(hdr->nr),
1171 	    _this->snd_nxt, _this->snd_una, _this->rcv_nxt));
1172 
1173 	if (L2TP_CTRL_CONF(_this)->ctrl_out_pktdump  != 0) {
1174 		l2tpd_log(_this->l2tpd, LOG_DEBUG,
1175 		    "L2TP Control output packet dump");
1176 		show_hd(debug_get_debugfp(), bytebuffer_pointer(bytebuf),
1177 		    bytebuffer_remaining(bytebuf));
1178 	}
1179 
1180 	if ((rval = l2tp_ctrl_send(_this, bytebuffer_pointer(bytebuf),
1181 	    bytebuffer_remaining(bytebuf))) < 0) {
1182 		L2TP_CTRL_DBG((_this, LOG_DEBUG, "sendto() failed: %m"));
1183 	}
1184 
1185 	_this->last_snd_ctrl = curr_time;
1186 
1187 	return (rval == bytebuffer_remaining(bytebuf))? 0 : 1;
1188 }
1189 
1190 /*
1191  * receiver SCCRQ
1192  */
1193 static int
1194 l2tp_ctrl_recv_SCCRQ(l2tp_ctrl *_this, u_char *pkt, int pktlen, l2tpd *_l2tpd,
1195     struct sockaddr *peer)
1196 {
1197 	int avpsz, len, protover, protorev, firmrev, result;
1198 	struct l2tp_avp *avp;
1199 	char host[NI_MAXHOST], serv[NI_MAXSERV];
1200 	char buf[L2TP_AVP_MAXSIZ], emes[256], hostname[256], vendorname[256];
1201 
1202 	result = L2TP_STOP_CCN_RCODE_GENERAL_ERROR;
1203 	strlcpy(hostname, "(no hostname)", sizeof(hostname));
1204 	strlcpy(vendorname, "(no vendorname)", sizeof(vendorname));
1205 
1206 	firmrev = 0;
1207 	protover = 0;
1208 	protorev = 0;
1209 	avp = (struct l2tp_avp *)buf;
1210 	while (pktlen >= 6 && (avpsz = avp_enum(avp, pkt, pktlen, 1)) > 0) {
1211 		pkt += avpsz;
1212 		pktlen -= avpsz;
1213 		if (avp->vendor_id != 0) {
1214 			L2TP_CTRL_DBG((_this, LOG_DEBUG,
1215 			    "Received a Vendor-specific AVP vendor-id=%d "
1216 			    "type=%d", avp->vendor_id, avp->attr_type));
1217 			continue;
1218 		}
1219 		switch (avp->attr_type) {
1220 		case L2TP_AVP_TYPE_MESSAGE_TYPE:
1221 			AVP_SIZE_CHECK(avp, ==, 8);
1222 			continue;
1223 		case L2TP_AVP_TYPE_PROTOCOL_VERSION:
1224 			AVP_SIZE_CHECK(avp, ==, 8);
1225 			protover = avp->attr_value[0];
1226 			protorev = avp->attr_value[1];
1227 
1228 			if (protover != L2TP_RFC2661_VERSION ||
1229 			    protorev != L2TP_RFC2661_REVISION) {
1230 				result = L2TP_STOP_CCN_RCODE_GENERAL_ERROR;
1231 				snprintf(emes, sizeof(emes),
1232 				    "Peer's protocol version is not supported:"
1233 				    " %d.%d", protover, protorev);
1234 				goto not_acceptable;
1235 			}
1236 			continue;
1237 		case L2TP_AVP_TYPE_FRAMING_CAPABILITIES:
1238 			AVP_SIZE_CHECK(avp, ==, 10);
1239 			if ((avp_get_val32(avp) & L2TP_FRAMING_CAP_FLAGS_SYNC)
1240 			    == 0) {
1241 				L2TP_CTRL_DBG((_this, LOG_DEBUG, "Peer doesn't "
1242 				    "support synchronous framing"));
1243 			}
1244 			continue;
1245 		case L2TP_AVP_TYPE_BEARER_CAPABILITIES:
1246 			AVP_SIZE_CHECK(avp, ==, 10);
1247 			continue;
1248 		case L2TP_AVP_TYPE_TIE_BREAKER:
1249 			AVP_SIZE_CHECK(avp, ==, 14);
1250 			/*
1251 			 * As the implementation never send SCCRQ,
1252 			 * the peer is always winner
1253 			 */
1254 			continue;
1255 		case L2TP_AVP_TYPE_FIRMWARE_REVISION:
1256 			AVP_SIZE_CHECK(avp, >=, 6);
1257 			firmrev = avp_get_val16(avp);
1258 			continue;
1259 		case L2TP_AVP_TYPE_HOST_NAME:
1260 			AVP_SIZE_CHECK(avp, >, 4);
1261 			len = MINIMUM(sizeof(hostname) - 1, avp->length - 6);
1262 			memcpy(hostname, avp->attr_value, len);
1263 			hostname[len] = '\0';
1264 			continue;
1265 		case L2TP_AVP_TYPE_VENDOR_NAME:
1266 			AVP_SIZE_CHECK(avp, >, 4);
1267 			len = MINIMUM(sizeof(vendorname) - 1, avp->length - 6);
1268 			memcpy(vendorname, avp->attr_value, len);
1269 			vendorname[len] = '\0';
1270 			continue;
1271 		case L2TP_AVP_TYPE_ASSINGED_TUNNEL_ID:
1272 			AVP_SIZE_CHECK(avp, ==, 8);
1273 			_this->peer_tunnel_id = avp_get_val16(avp);
1274 			continue;
1275 		case L2TP_AVP_TYPE_RECV_WINDOW_SIZE:
1276 			AVP_SIZE_CHECK(avp, ==, 8);
1277 			_this->peer_winsz = avp_get_val16(avp);
1278 			continue;
1279 		}
1280 		if (avp->is_mandatory) {
1281 			l2tp_ctrl_log(_this, LOG_WARNING,
1282 			    "Received AVP (%s/%d) is not supported, but it's "
1283 			    "mandatory", avp_attr_type_string(avp->attr_type),
1284 			    avp->attr_type);
1285 #ifdef L2TP_CTRL_DEBUG
1286 		} else {
1287 			L2TP_CTRL_DBG((_this, LOG_DEBUG,
1288 			    "AVP (%s/%d) is not handled",
1289 			    avp_attr_type_string(avp->attr_type),
1290 			    avp->attr_type));
1291 #endif
1292 		}
1293 	}
1294 	if (getnameinfo((struct sockaddr *)&_this->peer, _this->peer.ss_len,
1295 	    host, sizeof(host), serv, sizeof(serv),
1296 	    NI_NUMERICHOST | NI_NUMERICSERV | NI_DGRAM) != 0) {
1297 		l2tp_ctrl_log(_this, LOG_ERR,
1298 		    "getnameinfo() failed at %s(): %m", __func__);
1299 		strlcpy(host, "error", sizeof(host));
1300 		strlcpy(serv, "error", sizeof(serv));
1301 	}
1302 	l2tp_ctrl_log(_this, LOG_NOTICE, "logtype=Started RecvSCCRQ "
1303 	    "from=%s:%s/udp tunnel_id=%u/%u protocol=%d.%d winsize=%d "
1304 	    "hostname=%s vendor=%s firm=%04X", host, serv, _this->tunnel_id,
1305 	    _this->peer_tunnel_id, protover, protorev, _this->peer_winsz,
1306 	    hostname, vendorname, firmrev);
1307 
1308 	return 0;
1309 not_acceptable:
1310 size_check_failed:
1311 	l2tp_ctrl_log(_this, LOG_ERR, "Received bad SCCRQ: %s", emes);
1312 	l2tp_ctrl_stop(_this, result);
1313 
1314 	return 1;
1315 }
1316 
1317 /*
1318  * send StopCCN
1319  */
1320 static int
1321 l2tp_ctrl_send_StopCCN(l2tp_ctrl *_this, int result)
1322 {
1323 	struct l2tp_avp *avp;
1324 	char buf[L2TP_AVP_MAXSIZ];
1325 	bytebuffer *bytebuf;
1326 
1327 	if ((bytebuf = l2tp_ctrl_prepare_snd_buffer(_this, 1)) == NULL) {
1328 		l2tp_ctrl_log(_this, LOG_ERR,
1329 		    "sending StopCCN failed: no buffer.");
1330 		return -1;
1331 	}
1332 	avp = (struct l2tp_avp *)buf;
1333 
1334 	/* Message Type = StopCCN */
1335 	memset(avp, 0, sizeof(*avp));
1336 	avp->is_mandatory = 1;
1337 	avp->attr_type = L2TP_AVP_TYPE_MESSAGE_TYPE;
1338 	avp_set_val16(avp, L2TP_AVP_MESSAGE_TYPE_StopCCN);
1339 	bytebuf_add_avp(bytebuf, avp, 2);
1340 
1341 	/* Assigned Tunnel Id */
1342 	memset(avp, 0, sizeof(*avp));
1343 	avp->is_mandatory = 1;
1344 	avp->attr_type = L2TP_AVP_TYPE_ASSINGED_TUNNEL_ID;
1345 	avp_set_val16(avp, _this->tunnel_id);
1346 	bytebuf_add_avp(bytebuf, avp, 2);
1347 
1348 	/* Result Code */
1349 	memset(avp, 0, sizeof(*avp));
1350 	avp->is_mandatory = 1;
1351 	avp->attr_type = L2TP_AVP_TYPE_RESULT_CODE;
1352 	avp_set_val16(avp, result);
1353 	bytebuf_add_avp(bytebuf, avp, 2);
1354 
1355 	if (l2tp_ctrl_send_packet(_this, 0, bytebuf) != 0) {
1356 		l2tp_ctrl_log(_this, LOG_ERR, "sending StopCCN failed");
1357 		return - 1;
1358 	}
1359 	l2tp_ctrl_log(_this, LOG_INFO, "SendStopCCN result=%d", result);
1360 
1361 	return 0;
1362 }
1363 
1364 /*
1365  * Receiver StopCCN
1366  */
1367 static int
1368 l2tp_ctrl_recv_StopCCN(l2tp_ctrl *_this, u_char *pkt, int pktlen)
1369 {
1370 	int result, error, avpsz, len;
1371 	uint16_t tunid;
1372 	struct l2tp_avp *avp;
1373 	char buf[L2TP_AVP_MAXSIZ + 16], emes[256], pmes[256];
1374 
1375 	result = 0;
1376 	error = 0;
1377 	tunid = 0;
1378 	pmes[0] = '\0';
1379 	avp = (struct l2tp_avp *)buf;
1380 	while (pktlen >= 6 && (avpsz = avp_enum(avp, pkt, pktlen, 1)) > 0) {
1381 		pkt += avpsz;
1382 		pktlen -= avpsz;
1383 		if (avp->vendor_id != 0) {
1384 			L2TP_CTRL_DBG((_this, LOG_DEBUG,
1385 			    "Received a Vendor-specific AVP vendor-id=%d "
1386 			    "type=%d", avp->vendor_id, avp->attr_type));
1387 			continue;
1388 		}
1389 		if (avp->is_hidden != 0) {
1390 			l2tp_ctrl_log(_this, LOG_WARNING,
1391 			    "Received AVP (%s/%d) is hidden.  But we don't "
1392 			    "share secret.",
1393 			    avp_attr_type_string(avp->attr_type),
1394 			    avp->attr_type);
1395 			if (avp->is_mandatory != 0) {
1396 				l2tp_ctrl_stop(_this,
1397 				    L2TP_STOP_CCN_RCODE_GENERAL_ERROR |
1398 				    L2TP_ECODE_UNKNOWN_MANDATORY_AVP);
1399 				return 1;
1400 			}
1401 			continue;
1402 		}
1403 		switch (avp->attr_type) {
1404 		case L2TP_AVP_TYPE_MESSAGE_TYPE:
1405 			AVP_SIZE_CHECK(avp, ==, 8);
1406 			continue;
1407 		case L2TP_AVP_TYPE_RESULT_CODE:
1408 			AVP_SIZE_CHECK(avp, >=, 8);
1409 			result = avp->attr_value[0] << 8 | avp->attr_value[1];
1410 			if (avp->length >= 10) {
1411 				error = avp->attr_value[2] << 8 |
1412 				    avp->attr_value[3];
1413 				len = avp->length - 12;
1414 				if (len > 0) {
1415 					len = MINIMUM(len, sizeof(pmes) - 1);
1416 					memcpy(pmes, &avp->attr_value[4], len);
1417 					pmes[len] = '\0';
1418 				}
1419 			}
1420 			continue;
1421 		case L2TP_AVP_TYPE_ASSINGED_TUNNEL_ID:
1422 			AVP_SIZE_CHECK(avp, ==, 8);
1423 			tunid = avp_get_val16(avp);
1424 			continue;
1425 		default:
1426 			if (avp->is_mandatory != 0) {
1427 				l2tp_ctrl_log(_this, LOG_WARNING,
1428 				    "Received AVP (%s/%d) is not supported, "
1429 				    "but it's mandatory",
1430 				    avp_attr_type_string(avp->attr_type),
1431 				    avp->attr_type);
1432 #ifdef L2TP_CTRL_DEBUG
1433 			} else {
1434 				L2TP_CTRL_DBG((_this, LOG_DEBUG,
1435 				    "AVP (%s/%d) is not handled",
1436 				    avp_attr_type_string(avp->attr_type),
1437 				    avp->attr_type));
1438 #endif
1439 			}
1440 		}
1441 	}
1442 
1443 	if (result == L2TP_CDN_RCODE_ERROR_CODE &&
1444 	    error == L2TP_ECODE_NO_RESOURCE) {
1445 		/*
1446 		 * Memo:
1447 		 * This state may be happen in following state.
1448 		 * - lots of connect/disconect by long-running
1449 		 *   windows2000, sometimes it fall to this state.
1450 		 *   Once it fall to here, connection will fail till
1451 		 *   the windows rebooted
1452 		 */
1453 		l2tp_ctrl_log(_this, LOG_WARNING,
1454 		    "Peer indicates \"No Resource\" error.");
1455 	}
1456 
1457 	l2tp_ctrl_log(_this, LOG_INFO, "RecvStopCCN result=%s/%u "
1458 	    "error=%s/%u tunnel_id=%u message=\"%s\"",
1459 	    l2tp_stopccn_rcode_string(result), result,
1460 	    l2tp_ecode_string(error), error, tunid, pmes);
1461 
1462 	return 0;
1463 
1464 size_check_failed:
1465 	l2tp_ctrl_log(_this, LOG_ERR, "Received bad StopCCN: %s", emes);
1466 
1467 	return -1;
1468 }
1469 
1470 /*
1471  * send SCCRP
1472  */
1473 static void
1474 l2tp_ctrl_send_SCCRP(l2tp_ctrl *_this)
1475 {
1476 	int len;
1477 	struct l2tp_avp *avp;
1478 	char buf[L2TP_AVP_MAXSIZ], hbuf[HOST_NAME_MAX+1];
1479 	const char *val;
1480 	bytebuffer *bytebuf;
1481 
1482 	if ((bytebuf = l2tp_ctrl_prepare_snd_buffer(_this, 1)) == NULL) {
1483 		l2tp_ctrl_log(_this, LOG_ERR,
1484 		    "sending SCCRP failed: no buffer.");
1485 		return;
1486 	}
1487 	avp = (struct l2tp_avp *)buf;
1488 
1489 	/* Message Type = SCCRP */
1490 	memset(avp, 0, sizeof(*avp));
1491 	avp->is_mandatory = 1;
1492 	avp->attr_type = L2TP_AVP_TYPE_MESSAGE_TYPE;
1493 	avp_set_val16(avp, L2TP_AVP_MESSAGE_TYPE_SCCRP);
1494 	bytebuf_add_avp(bytebuf, avp, 2);
1495 
1496 	/* Protocol Version = 1.0 */
1497 	memset(avp, 0, sizeof(*avp));
1498 	avp->is_mandatory = 1;
1499 	avp->attr_type = L2TP_AVP_TYPE_PROTOCOL_VERSION;
1500 	avp->attr_value[0] = L2TP_RFC2661_VERSION;
1501 	avp->attr_value[1] = L2TP_RFC2661_REVISION;
1502 	bytebuf_add_avp(bytebuf, avp, 2);
1503 
1504 	/* Framing Capability = Async */
1505 	memset(avp, 0, sizeof(*avp));
1506 	avp->is_mandatory = 1;
1507 	avp->attr_type = L2TP_AVP_TYPE_FRAMING_CAPABILITIES;
1508 	avp_set_val32(avp, L2TP_FRAMING_CAP_FLAGS_SYNC);
1509 	bytebuf_add_avp(bytebuf, avp, 4);
1510 
1511 	/* Host Name */
1512 	memset(avp, 0, sizeof(*avp));
1513 	avp->is_mandatory = 1;
1514 	avp->attr_type = L2TP_AVP_TYPE_HOST_NAME;
1515 	if ((val = L2TP_CTRL_CONF(_this)->hostname) == NULL) {
1516 		gethostname(hbuf, sizeof(hbuf));
1517 		val = hbuf;
1518 	}
1519 	len = strlen(val);
1520 	memcpy(avp->attr_value, val, len);
1521 	bytebuf_add_avp(bytebuf, avp, len);
1522 
1523 	/* Assigned Tunnel Id */
1524 	memset(avp, 0, sizeof(*avp));
1525 	avp->is_mandatory = 1;
1526 	avp->attr_type = L2TP_AVP_TYPE_ASSINGED_TUNNEL_ID;
1527 	avp_set_val16(avp, _this->tunnel_id);
1528 	bytebuf_add_avp(bytebuf, avp, 2);
1529 
1530 	/* Bearer Capability
1531 	 * This implementation never act as LAC.
1532 	 *
1533 	memset(avp, 0, sizeof(*avp));
1534 	avp->is_mandatory = 1;
1535 	avp->attr_type = L2TP_AVP_TYPE_BEARER_CAPABILITIES;
1536 	avp_set_val32(avp, 0);
1537 	bytebuf_add_avp(bytebuf, avp, 4);
1538 	 */
1539 
1540 	/* Firmware Revision */
1541 	memset(avp, 0, sizeof(*avp));
1542 	avp->is_mandatory = 0;
1543 	avp->attr_type = L2TP_AVP_TYPE_FIRMWARE_REVISION;
1544 	avp->attr_value[0] = MAJOR_VERSION;
1545 	avp->attr_value[1] = MINOR_VERSION;
1546 	bytebuf_add_avp(bytebuf, avp, 2);
1547 
1548 	/* Vendor Name */
1549 	if ((val = L2TP_CTRL_CONF(_this)->vendor_name) != NULL) {
1550 		memset(avp, 0, sizeof(*avp));
1551 		avp->is_mandatory = 0;
1552 		avp->attr_type = L2TP_AVP_TYPE_VENDOR_NAME;
1553 
1554 		len = strlen(val);
1555 		memcpy(avp->attr_value, val, len);
1556 		bytebuf_add_avp(bytebuf, avp, len);
1557 	}
1558 
1559 	/* Window Size */
1560 	memset(avp, 0, sizeof(*avp));
1561 	avp->is_mandatory = 1;
1562 	avp->attr_type = L2TP_AVP_TYPE_RECV_WINDOW_SIZE;
1563 	avp_set_val16(avp, _this->winsz);
1564 	bytebuf_add_avp(bytebuf, avp, 2);
1565 
1566 	if ((l2tp_ctrl_send_packet(_this, 0, bytebuf)) != 0) {
1567 		l2tp_ctrl_log(_this, LOG_ERR, "sending SCCRP failed");
1568 		l2tp_ctrl_stop(_this, L2TP_STOP_CCN_RCODE_GENERAL);
1569 		return;
1570 	}
1571 	l2tp_ctrl_log(_this, LOG_INFO, "SendSCCRP");
1572 }
1573 
1574 static int
1575 l2tp_ctrl_send_HELLO(l2tp_ctrl *_this)
1576 {
1577 	struct l2tp_avp *avp;
1578 	char buf[L2TP_AVP_MAXSIZ];
1579 	bytebuffer *bytebuf;
1580 
1581 	if ((bytebuf = l2tp_ctrl_prepare_snd_buffer(_this, 1)) == NULL) {
1582 		l2tp_ctrl_log(_this, LOG_ERR,
1583 		    "sending SCCRP failed: no buffer.");
1584 		return 1;
1585 	}
1586 	avp = (struct l2tp_avp *)buf;
1587 
1588 	/* Message Type = HELLO */
1589 	memset(avp, 0, sizeof(*avp));
1590 	avp->is_mandatory = 1;
1591 	avp->attr_type = L2TP_AVP_TYPE_MESSAGE_TYPE;
1592 	avp_set_val16(avp, L2TP_AVP_MESSAGE_TYPE_HELLO);
1593 	bytebuf_add_avp(bytebuf, avp, 2);
1594 
1595 	if ((l2tp_ctrl_send_packet(_this, 0, bytebuf)) != 0) {
1596 		l2tp_ctrl_log(_this, LOG_ERR, "sending HELLO failed");
1597 		l2tp_ctrl_stop(_this, L2TP_STOP_CCN_RCODE_GENERAL);
1598 		return 1;
1599 	}
1600 	l2tp_ctrl_log(_this, LOG_DEBUG, "SendHELLO");
1601 
1602 	return 0;
1603 }
1604 
1605 /* Send  ZLB */
1606 static int
1607 l2tp_ctrl_send_ZLB(l2tp_ctrl *_this)
1608 {
1609 	int loglevel;
1610 
1611 	loglevel = (_this->state == L2TP_CTRL_STATE_ESTABLISHED)
1612 	    ? LOG_DEBUG : LOG_INFO;
1613 	l2tp_ctrl_log(_this, loglevel, "SendZLB");
1614 	bytebuffer_clear(_this->zlb_buffer);
1615 	bytebuffer_put(_this->zlb_buffer, BYTEBUFFER_PUT_DIRECT,
1616 	    sizeof(struct l2tp_header));
1617 
1618 	return l2tp_ctrl_send_packet(_this, 0, _this->zlb_buffer);
1619 }
1620 
1621 /*
1622  * Utitlity
1623  */
1624 
1625 /**
1626  * Prepare send buffer
1627  * @return return Null when the send buffer exceed Window.
1628  */
1629 bytebuffer *
1630 l2tp_ctrl_prepare_snd_buffer(l2tp_ctrl *_this, int with_seq)
1631 {
1632 	bytebuffer *bytebuf;
1633 
1634 	L2TP_CTRL_ASSERT(_this != NULL);
1635 
1636 	if (l2tp_ctrl_txwin_is_full(_this)) {
1637 		l2tp_ctrl_log(_this, LOG_INFO, "sending buffer is full.");
1638 		return NULL;
1639 	}
1640 	bytebuf = _this->snd_buffers[_this->snd_nxt % _this->winsz];
1641 	bytebuffer_clear(bytebuf);
1642 	if (with_seq)
1643 		bytebuffer_put(bytebuf, BYTEBUFFER_PUT_DIRECT,
1644 		    sizeof(struct l2tp_header));
1645 	else
1646 		bytebuffer_put(bytebuf, BYTEBUFFER_PUT_DIRECT,
1647 		    offsetof(struct l2tp_header, ns));
1648 
1649 	return bytebuf;
1650 }
1651 
1652 /**
1653  * return current state as strings
1654  */
1655 static inline const char *
1656 l2tp_ctrl_state_string(l2tp_ctrl *_this)
1657 {
1658 	switch (_this->state) {
1659 	case L2TP_CTRL_STATE_IDLE:		return "idle";
1660 	case L2TP_CTRL_STATE_WAIT_CTL_CONN:	return "wait-ctl-conn";
1661 	case L2TP_CTRL_STATE_WAIT_CTL_REPLY:	return "wait-ctl-reply";
1662 	case L2TP_CTRL_STATE_ESTABLISHED:	return "established";
1663 	case L2TP_CTRL_STATE_CLEANUP_WAIT:	return "cleanup-wait";
1664 	}
1665 	return "unknown";
1666 }
1667 
1668 /* logging with the label of the l2tp instance. */
1669 void
1670 l2tp_ctrl_log(l2tp_ctrl *_this, int prio, const char *fmt, ...)
1671 {
1672 	char logbuf[BUFSIZ];
1673 	va_list ap;
1674 
1675 	va_start(ap, fmt);
1676 #ifdef	L2TPD_MULTIPLE
1677 	snprintf(logbuf, sizeof(logbuf), "l2tpd id=%u ctrl=%u %s",
1678 	    _this->l2tpd->id, _this->id, fmt);
1679 #else
1680 	snprintf(logbuf, sizeof(logbuf), "l2tpd ctrl=%u %s", _this->id, fmt);
1681 #endif
1682 	vlog_printf(prio, logbuf, ap);
1683 	va_end(ap);
1684 }
1685