X-Git-Url: http://git.sameswireless.fr/l2tpns.git/blobdiff_plain/f7a59cd6cca9d4188566c9ca9870edfb24f9b0a0..a5da286a96eeddee654861fd1da18735d26b9bf7:/ppp.c?ds=inline

diff --git a/ppp.c b/ppp.c
index e162f06..f0e47e0 100644
--- a/ppp.c
+++ b/ppp.c
@@ -1,6 +1,6 @@
 // L2TPNS PPP Stuff
 
-char const *cvs_id_ppp = "$Id: ppp.c,v 1.10 2004-08-02 05:40:21 fred_nerk Exp $";
+char const *cvs_id_ppp = "$Id: ppp.c,v 1.26 2004-11-16 07:54:32 bodea Exp $";
 
 #include <stdio.h>
 #include <string.h>
@@ -23,36 +23,40 @@ extern u32 eth_tx;
 extern time_t time_now;
 extern struct configt *config;
 
-void sendccp(tunnelidt t, sessionidt s);
+static void sendccp(tunnelidt t, sessionidt s);
 
 // Process PAP messages
-void processpap(tunnelidt t, sessionidt s, u8 * p, u16 l)
+void processpap(tunnelidt t, sessionidt s, u8 *p, u16 l)
 {
 	char user[129];
 	char pass[129];
-
+	u16 hl;
 
 	CSTAT(call_processpap);
 
-	log_hex(5, "PAP", p, l);
+	LOG_HEX(5, "PAP", p, l);
 	if (l < 4)
 	{
-		log(1, 0, s, t, "Short PAP %u bytes\n", l);
+		LOG(1, 0, s, t, "Short PAP %u bytes\n", l);
 		STAT(tunnel_rx_errors);
 		return ;
 	}
-	if (*p != 1)
+
+	if ((hl = ntohs(*(u16 *) (p + 2))) > l)
 	{
-		log(1, 0, s, t, "Unexpected PAP code %d\n", *p);
+		LOG(1, 0, s, t, "Length mismatch PAP %u/%u\n", hl, l);
 		STAT(tunnel_rx_errors);
 		return ;
 	}
-	if (ntohs(*(u16 *) (p + 2)) > l)
+	l = hl;
+
+	if (*p != 1)
 	{
-		log(1, 0, s, t, "Length mismatch PAP %d/%d\n", ntohs(*(u16 *) (p + 2)), l);
+		LOG(1, 0, s, t, "Unexpected PAP code %d\n", *p);
 		STAT(tunnel_rx_errors);
 		return ;
 	}
+
 	{
 		u8 *b = p;
 		b += 4;
@@ -63,7 +67,7 @@ void processpap(tunnelidt t, sessionidt s, u8 * p, u16 l)
 		if (*b && *b < sizeof(pass))
 			memcpy(pass, b + 1, *b);
 		pass[*b] = 0;
-		log(3, 0, s, t, "PAP login %s/%s\n", user, pass);
+		LOG(3, 0, s, t, "PAP login %s/%s\n", user, pass);
 	}
 	if (session[s].ip || !session[s].radius)
 	{
@@ -72,30 +76,31 @@ void processpap(tunnelidt t, sessionidt s, u8 * p, u16 l)
 		u8 id = p[1];
 		u8 *p = makeppp(b, sizeof(b), 0, 0, t, s, PPPPAP);
 		if (!p) {	// Failed to make ppp header!
-			log(1,0,0,0, "Failed to make PPP header in process pap!\n");
+			LOG(1,0,0,0, "Failed to make PPP header in process pap!\n");
 			return;
 		}
 		if (session[s].ip)
-			*p = 2;              // ACK
+			*p = 2;			// ACK
 		else
-			*p = 3;              // cant authorise
+			*p = 3;			// cant authorise
 		p[1] = id;
-		*(u16 *) (p + 2) = htons(5); // length
-		p[4] = 0;               // no message
+		*(u16 *) (p + 2) = htons(5);	// length
+		p[4] = 0;			// no message
 		if (session[s].ip)
 		{
-		    log(3, session[s].ip, s, t, "%d Already an IP allocated: %s (%d)\n", getpid(), inet_toa(htonl(session[s].ip)), session[s].ip_pool_index);
+			LOG(3, session[s].ip, s, t, "Already an IP allocated: %s (%d)\n", inet_toa(htonl(session[s].ip)), session[s].ip_pool_index);
 			session[s].flags &= ~SF_IPCP_ACKED;
 		}
 		else
 		{
-		    log(1, 0, s, t, "No radius session available to authenticate session...\n");
+			LOG(1, 0, s, t, "No radius session available to authenticate session...\n");
 		}
-		log(3, 0, s, t, "Fallback response to PAP (%s)\n", (session[s].ip) ? "ACK" : "NAK");
+		LOG(3, 0, s, t, "Fallback response to PAP (%s)\n", (session[s].ip) ? "ACK" : "NAK");
 		tunnelsend(b, 5 + (p - b), t); // send it
 	}
 	else
-	{                          // set up RADIUS request
+	{
+		// set up RADIUS request
 		u16 r = session[s].radius;
 
 		// Run PRE_AUTH plugins
@@ -103,7 +108,7 @@ void processpap(tunnelidt t, sessionidt s, u8 * p, u16 l)
 		run_plugins(PLUGIN_PRE_AUTH, &packet);
 		if (!packet.continue_auth)
 		{
-			log(3, 0, s, t, "A plugin rejected PRE_AUTH\n");
+			LOG(3, 0, s, t, "A plugin rejected PRE_AUTH\n");
 			if (packet.username) free(packet.username);
 			if (packet.password) free(packet.password);
 			return;
@@ -116,59 +121,71 @@ void processpap(tunnelidt t, sessionidt s, u8 * p, u16 l)
 		free(packet.password);
 
 		radius[r].id = p[1];
-		log(3, 0, s, t, "Sending login for %s/%s to radius\n", user, pass);
+		LOG(3, 0, s, t, "Sending login for %s/%s to radius\n", user, pass);
 		radiussend(r, RADIUSAUTH);
 	}
 }
 
 // Process CHAP messages
-void processchap(tunnelidt t, sessionidt s, u8 * p, u16 l)
+void processchap(tunnelidt t, sessionidt s, u8 *p, u16 l)
 {
 	u16 r;
-	u16 len;
-
+	u16 hl;
 
 	CSTAT(call_processchap);
 
-	log_hex(5, "CHAP", p, l);
+	LOG_HEX(5, "CHAP", p, l);
 	r = session[s].radius;
 	if (!r)
 	{
-		log(1, 0, s, t, "Unexpected CHAP message\n");
+		LOG(1, 0, s, t, "Unexpected CHAP message\n");
 
 // FIXME: Need to drop the session here.
 
 		STAT(tunnel_rx_errors);
 		return;
 	}
-	if (*p != 2)
+
+	if (l < 4)
 	{
-		log(1, 0, s, t, "Unexpected CHAP response code %d\n", *p);
+		LOG(1, 0, s, t, "Short CHAP %u bytes\n", l);
 		STAT(tunnel_rx_errors);
-		return;
+		return ;
 	}
-	if (p[1] != radius[r].id)
+
+	if ((hl = ntohs(*(u16 *) (p + 2))) > l)
 	{
-		log(1, 0, s, t, "Wrong CHAP response ID %d (should be %d) (%d)\n", p[1], radius[r].id, r);
+		LOG(1, 0, s, t, "Length mismatch CHAP %u/%u\n", hl, l);
 		STAT(tunnel_rx_errors);
 		return ;
 	}
-	len = ntohs(*(u16 *) (p + 2));
-	if (len > l)
+	l = hl;
+
+	if (*p != 2)
+	{
+		LOG(1, 0, s, t, "Unexpected CHAP response code %d\n", *p);
+		STAT(tunnel_rx_errors);
+		return;
+	}
+	if (p[1] != radius[r].id)
 	{
-		log(1, 0, s, t, "Bad CHAP length %d\n", len);
+		LOG(1, 0, s, t, "Wrong CHAP response ID %d (should be %d) (%d)\n", p[1], radius[r].id, r);
 		STAT(tunnel_rx_errors);
 		return ;
 	}
-	if (p[4] != 16)
+
+	if (l < 5 || p[4] != 16)
 	{
-		log(1, 0, s, t, "Bad CHAP response length %d\n", p[4]);
+		LOG(1, 0, s, t, "Bad CHAP response length %d\n", l < 5 ? -1 : p[4]);
 		STAT(tunnel_rx_errors);
 		return ;
 	}
-	if (len - 21 >= sizeof(session[s].user))
+
+	l -= 5;
+	p += 5;
+	if (l < 16 || l - 16 >= sizeof(session[s].user))
 	{
-		log(1, 0, s, t, "CHAP user too long %d\n", len - 21);
+		LOG(1, 0, s, t, "CHAP user too long %d\n", l - 16);
 		STAT(tunnel_rx_errors);
 		return ;
 	}
@@ -177,15 +194,19 @@ void processchap(tunnelidt t, sessionidt s, u8 * p, u16 l)
 	{
 		struct param_pre_auth packet = { &tunnel[t], &session[s], NULL, NULL, PPPCHAP, 1 };
 
-		packet.username = calloc(len-20, 1);
-		packet.password = calloc(16, 1);
-		memcpy(packet.username, p + 21, len - 21);
-		memcpy(packet.password, p + 5, 16);
+		packet.password = calloc(17, 1);
+		memcpy(packet.password, p, 16);
+
+		p += 16;
+		l -= 16;
+
+		packet.username = calloc(l + 1, 1);
+		memcpy(packet.username, p, l);
 
 		run_plugins(PLUGIN_PRE_AUTH, &packet);
 		if (!packet.continue_auth)
 		{
-			log(3, 0, s, t, "A plugin rejected PRE_AUTH\n");
+			LOG(3, 0, s, t, "A plugin rejected PRE_AUTH\n");
 			if (packet.username) free(packet.username);
 			if (packet.password) free(packet.password);
 			return;
@@ -199,11 +220,11 @@ void processchap(tunnelidt t, sessionidt s, u8 * p, u16 l)
 	}
 
 	radius[r].chap = 1;
-	log(3, 0, s, t, "CHAP login %s\n", session[s].user);
+	LOG(3, 0, s, t, "CHAP login %s\n", session[s].user);
 	radiussend(r, RADIUSAUTH);
 }
 
-char *ppp_lcp_types[] = {
+static char *ppp_lcp_types[] = {
 	NULL,
 	"ConfigReq",
 	"ConfigAck",
@@ -219,14 +240,14 @@ char *ppp_lcp_types[] = {
 	"IdentRequest",
 };
 
-void dumplcp(u8 *p, int l)
+static void dumplcp(u8 *p, int l)
 {
-	signed int x = l - 4;
+	int x = l - 4;
 	u8 *o = (p + 4);
 
-	log_hex(5, "PPP LCP Packet", p, l);
-	log(4, 0, 0, 0, "PPP LCP Packet type %d (%s len %d)\n", *p, ppp_lcp_types[(int)*p], ntohs( ((u16 *) p)[1]) );
-	log(4, 0, 0, 0, "Length: %d\n", l);
+	LOG_HEX(5, "PPP LCP Packet", p, l);
+	LOG(4, 0, 0, 0, "PPP LCP Packet type %d (%s len %d)\n", *p, ppp_lcp_types[(int)*p], ntohs( ((u16 *) p)[1]) );
+	LOG(4, 0, 0, 0, "Length: %d\n", l);
 	if (*p != ConfigReq && *p != ConfigRej && *p != ConfigAck)
 		return;
 
@@ -236,12 +257,12 @@ void dumplcp(u8 *p, int l)
 		int length = o[1];
 		if (length < 2)
 		{
-			log(4, 0, 0, 0, "	Option length is %d...\n", length);
+			LOG(4, 0, 0, 0, "	Option length is %d...\n", length);
 			break;
 		}
 		if (type == 0)
 		{
-			log(4, 0, 0, 0, "	Option type is 0...\n");
+			LOG(4, 0, 0, 0, "	Option type is 0...\n");
 			x -= length;
 			o += length;
 			continue;
@@ -250,52 +271,51 @@ void dumplcp(u8 *p, int l)
 		{
 			case 1: // Maximum-Receive-Unit
 				if (length == 4)
-				log(4, 0, 0, 0, "    %s %d\n", lcp_types[type], ntohs(*(u16 *)(o + 2)));
+					LOG(4, 0, 0, 0, "    %s %d\n", lcp_types[type], ntohs(*(u16 *)(o + 2)));
+				else
+					LOG(4, 0, 0, 0, "    %s odd length %d\n", lcp_types[type], length);
+				break;
+			case 2: // Async-Control-Character-Map
+				if (length == 6)
+				{
+					u32 asyncmap = ntohl(*(u32 *)(o + 2));
+					LOG(4, 0, 0, 0, "    %s %x\n", lcp_types[type], asyncmap);
+				}
 				else
-					log(4, 0, 0, 0, "    %s odd length %d\n", lcp_types[type], length);
+					LOG(4, 0, 0, 0, "   %s odd length %d\n", lcp_types[type], length);
 				break;
 			case 3: // Authentication-Protocol
+				if (length == 4)
 				{
-					if (length == 4)
-					{
 					int proto = ntohs(*(u16 *)(o + 2));
-						log(4, 0, 0, 0, "   %s 0x%x (%s)\n", lcp_types[type], proto,
-							proto == 0xC223 ? "CHAP" :
-							proto == 0xC023 ? "PAP"  : "UNKNOWN");
-					}
-					else
-						log(4, 0, 0, 0, "   %s odd length %d\n", lcp_types[type], length);
-					break;
+					LOG(4, 0, 0, 0, "   %s 0x%x (%s)\n", lcp_types[type], proto,
+						proto == PPPCHAP ? "CHAP" :
+						proto == PPPPAP  ? "PAP"  : "UNKNOWN");
 				}
+				else
+					LOG(4, 0, 0, 0, "   %s odd length %d\n", lcp_types[type], length);
+				break;
 			case 4: // Quality-Protocol
 				{
 					u32 qp = ntohl(*(u32 *)(o + 2));
-					log(4, 0, 0, 0, "    %s %x\n", lcp_types[type], qp);
-					break;
+					LOG(4, 0, 0, 0, "    %s %x\n", lcp_types[type], qp);
 				}
+				break;
 			case 5: // Magic-Number
+				if (length == 6)
 				{
-					if (length == 6)
-					{
 					u32 magicno = ntohl(*(u32 *)(o + 2));
-					log(4, 0, 0, 0, "    %s %x\n", lcp_types[type], magicno);
-					}
-					else
-						log(4, 0, 0, 0, "   %s odd length %d\n", lcp_types[type], length);
-					break;
+					LOG(4, 0, 0, 0, "    %s %x\n", lcp_types[type], magicno);
 				}
+				else
+					LOG(4, 0, 0, 0, "   %s odd length %d\n", lcp_types[type], length);
+				break;
 			case 7: // Protocol-Field-Compression
-				{
-					log(4, 0, 0, 0, "    %s\n", lcp_types[type]);
-					break;
-				}
 			case 8: // Address-And-Control-Field-Compression
-				{
-					log(4, 0, 0, 0, "    %s\n", lcp_types[type]);
-					break;
-				}
+				LOG(4, 0, 0, 0, "    %s\n", lcp_types[type]);
+				break;
 			default:
-				log(2, 0, 0, 0, "    Unknown PPP LCP Option type %d\n", type);
+				LOG(2, 0, 0, 0, "    Unknown PPP LCP Option type %d\n", type);
 				break;
 		}
 		x -= length;
@@ -304,147 +324,176 @@ void dumplcp(u8 *p, int l)
 }
 
 // Process LCP messages
-void processlcp(tunnelidt t, sessionidt s, u8 * p, u16 l)
+void processlcp(tunnelidt t, sessionidt s, u8 *p, u16 l)
 {
 	u8 b[MAXCONTROL];
 	u8 *q = NULL;
-	u32  magicno = 0;
-
+	u32 magicno = 0;
+	u16 hl;
 
 	CSTAT(call_processlcp);
 
-	log_hex(5, "LCP", p, l);
+	LOG_HEX(5, "LCP", p, l);
 	if (l < 4)
 	{
-		log(1, session[s].ip, s, t, "Short LCP %d bytes\n", l);
+		LOG(1, session[s].ip, s, t, "Short LCP %d bytes\n", l);
+		STAT(tunnel_rx_errors);
+		return ;
+	}
+
+	if ((hl = ntohs(*(u16 *) (p + 2))) > l)
+	{
+		LOG(1, 0, s, t, "Length mismatch LCP %u/%u\n", hl, l);
 		STAT(tunnel_rx_errors);
 		return ;
 	}
+	l = hl;
+
 	if (*p == ConfigAck)
 	{
-		log(3, session[s].ip, s, t, "LCP: Discarding ConfigAck\n");
-		session[s].flags |= SESSIONLCPACK;
+		LOG(3, session[s].ip, s, t, "LCP: Discarding ConfigAck\n");
+		session[s].flags |= SF_LCP_ACKED;
 	}
 	else if (*p == ConfigReq)
 	{
-		signed int x = l - 4;
+		int x = l - 4;
 		u8 *o = (p + 4);
+		u8 response = 0;
 
-		log(3, session[s].ip, s, t, "LCP: ConfigReq (%d bytes)...\n", l);
-		dumplcp(p, l);
+		LOG(3, session[s].ip, s, t, "LCP: ConfigReq (%d bytes)...\n", l);
+		if (config->debug > 3) dumplcp(p, l);
 
 		while (x > 2)
 		{
 			int type = o[0];
 			int length = o[1];
-			if (length == 0 || type == 0) break;
+			if (length == 0 || type == 0 || x < length) break;
 			switch (type)
 			{
 				case 1: // Maximum-Receive-Unit
 					session[s].mru = ntohs(*(u16 *)(o + 2));
 					break;
-				case 2: // asyncmap
-					log_hex(2, "PPP LCP Packet", p, l);
-					log(2, 0, 0, 0, "PPP LCP Packet type %d (%s len %d)\n", *p, ppp_lcp_types[(int)*p], ntohs( ((u16 *) p)[1]) );
+
+				case 2: // Async-Control-Character-Map
+					if (!ntohl(*(u32 *)(o + 2))) // all bits zero is OK
+						break;
+
+					if (response && response != ConfigNak) // rej already queued
+						break;
+
+					LOG(2, session[s].ip, s, t, "    Remote requesting asyncmap.  Rejecting.\n");
+					if (!response)
+					{
+						q = makeppp(b, sizeof(b), p, l, t, s, PPPLCP);
+						if (!q)
+						{
+							LOG(2, session[s].ip, s, t, " Failed to send packet.\n");
+							break;
+						}
+						response = *q++ = ConfigNak;
+					}
+					*q++ = type;
+					*q++ = 6;
+					memset(q, 0, 4); // asyncmap 0
+					q += 4;
 					break;
+
 				case 3: // Authentication-Protocol
 					{
 						int proto = ntohs(*(u16 *)(o + 2));
-						if (proto == 0xC223)
-						{
-							log(2, session[s].ip, s, t, "    Remote end is trying to do CHAP. Rejecting it.\n");
+						char proto_name[] = "0x0000";
+						if (proto == PPPPAP)
+							break;
+
+						if (response && response != ConfigNak) // rej already queued
+							break;
+
+						if (proto == PPPCHAP)
+							strcpy(proto_name, "CHAP");
+						else
+							sprintf(proto_name, "%#4.4x", proto);
 
+						LOG(2, session[s].ip, s, t, "    Remote requesting %s authentication.  Rejecting.\n", proto_name);
+
+						if (!response)
+						{
+							q = makeppp(b, sizeof(b), p, l, t, s, PPPLCP);
 							if (!q)
 							{
-								q = makeppp(b, sizeof(b), p, l, t, s, PPPLCP);
-								if (!q) {
-									log(2, session[s].ip, s, t, " Failed to send packet.\n");
-									break;
-								}
-								*q++ = ConfigNak;
+								LOG(2, session[s].ip, s, t, " Failed to send packet.\n");
+								break;
 							}
-							memcpy(q, o, length);
-							*(u16 *)(q += 2) = htons(0xC023); // NAK -> Use PAP instead
-							q += length;
+							response = *q++ = ConfigNak;
 						}
-						break;
+						memcpy(q, o, length);
+						*(u16 *)(q += 2) = htons(PPPPAP); // NAK -> Use PAP instead
+						q += length;
 					}
+					break;
+
 				case 5: // Magic-Number
-					{
-						magicno = ntohl(*(u32 *)(o + 2));
-						break;
-					}
+					magicno = ntohl(*(u32 *)(o + 2));
+					break;
+
 				case 4: // Quality-Protocol
 				case 7: // Protocol-Field-Compression
 				case 8: // Address-And-Control-Field-Compression
-						break;
-				case 13: // CallBack option for LCP extention of win2000/routers L2TP client
-				case 17:
-				case 18:
-				{
-					// Reject LCP CallBack
-					log(2, session[s].ip, s, t, "    PPP LCP Option type %d, len=%d\n", type, length);
-					memcpy(p + 4, o, length);
-					*(u16 *)(p + 2) = htons(length + 4);
-					*p = ConfigRej;
-					q = makeppp(b,sizeof(b), p, length + 4, t, s, PPPLCP);
-					tunnelsend(b, 12 + length + 4, t);
-					return;
+					break;
+
+				default: // Reject any unknown options
+					LOG(2, session[s].ip, s, t, "    Rejecting PPP LCP Option type %d\n", type);
+					if (!response || response != ConfigRej) // drop nak in favour of rej
+					{
+						q = makeppp(b, sizeof(b), p, l, t, s, PPPLCP);
+						if (!q)
+						{
+							LOG(2, session[s].ip, s, t, " Failed to send packet.\n");
+							break;
+						}
+						response = *q++ = ConfigRej;
 					}
 
-				default:
-					// Reject Unknown LCP Option to stop to send it again
-					log(2, session[s].ip, s, t, "    Unknown PPP LCP Option type %d\n", type);
-					memcpy(p + 4, o, length);
-					*(u16 *)(p + 2) = htons(length + 4);
-					*p = ConfigRej;
-					q = makeppp(b,sizeof(b), p, length + 4, t, s, PPPLCP);
-					tunnelsend(b, 12 + length + 4, t);
-					return;
+					memcpy(q, o, length);
+					q += length;
 			}
 			x -= length;
 			o += length;
 		}
 
-		if (!q)
+		if (!response)
 		{
 			// Send back a ConfigAck
-			log(3, session[s].ip, s, t, "ConfigReq accepted, sending as Ack\n");
 			q = makeppp(b, sizeof(b), p, l, t, s, PPPLCP);
-			if (!q) {
-				log(3, session[s].ip, s, t, " failed to create packet.\n");
+			if (!q)
+			{
+				LOG(3, session[s].ip, s, t, " failed to create packet.\n");
 				return;
 			}
-			*q = ConfigAck;
-			tunnelsend(b, l + (q - b), t);
-			// For win2k L2TP clients, LCP should be initiated by the LNS
-			if (magicno) initlcp(t, s);
-		}
-		else
-		{
-			// Already built a ConfigNak... send it
-			log(3, session[s].ip, s, t, "Sending ConfigNak\n");
-			tunnelsend(b, l + (q - b), t);
+			response = *q = ConfigAck;
 		}
 
-		if (!(session[s].flags & SESSIONLCPACK))
+		LOG(3, session[s].ip, s, t, "Sending %s\n", ppp_lcp_types[response]);
+		tunnelsend(b, l + (q - b), t);
+
+		if (!(session[s].flags & SF_LCP_ACKED))
 			initlcp(t, s);
 	}
 	else if (*p == ConfigNak)
 	{
-		log(1, session[s].ip, s, t, "Remote end sent a ConfigNak. Ignoring\n");
-		dumplcp(p, l);
+		LOG(1, session[s].ip, s, t, "Remote end sent a ConfigNak. Ignoring\n");
+		if (config->debug > 3) dumplcp(p, l);
 		return ;
 	}
 	else if (*p == TerminateReq)
 	{
-		*p = TerminateAck;     // close
+		*p = TerminateAck;	// close
 		q = makeppp(b, sizeof(b),  p, l, t, s, PPPLCP);
-		if (!q) {
-			log(3, session[s].ip, s, t, "Failed to create PPP packet in processlcp.\n");
+		if (!q)
+		{
+			LOG(3, session[s].ip, s, t, "Failed to create PPP packet in processlcp.\n");
 			return;
 		}
-		log(3, session[s].ip, s, t, "LCP: Received TerminateReq. Sending TerminateAck\n");
+		LOG(3, session[s].ip, s, t, "LCP: Received TerminateReq. Sending TerminateAck\n");
 		sessionshutdown(s, "Remote end closed connection.");
 		tunnelsend(b, l + (q - b), t); // send it
 	}
@@ -454,14 +503,15 @@ void processlcp(tunnelidt t, sessionidt s, u8 * p, u16 l)
 	}
 	else if (*p == EchoReq)
 	{
-		*p = EchoReply;      // reply
+		*p = EchoReply;		// reply
 		*(u32 *) (p + 4) = htonl(session[s].magic); // our magic number
 		q = makeppp(b, sizeof(b), p, l, t, s, PPPLCP);
-		if (!q) {
-			log(3, session[s].ip, s, t, " failed to send EchoReply.\n");
+		if (!q)
+		{
+			LOG(3, session[s].ip, s, t, " failed to send EchoReply.\n");
 			return;
 		}
-		log(5, session[s].ip, s, t, "LCP: Received EchoReq. Sending EchoReply\n");
+		LOG(5, session[s].ip, s, t, "LCP: Received EchoReq. Sending EchoReply\n");
 		tunnelsend(b, l + (q - b), t); // send it
 	}
 	else if (*p == EchoReply)
@@ -473,44 +523,75 @@ void processlcp(tunnelidt t, sessionidt s, u8 * p, u16 l)
 		*p = CodeRej;
 		if (l > MAXCONTROL)
 		{
-			log(1, 0, s, t, "Truncated Ident Packet (length=%d) to 1400 bytes\n", l);
+			LOG(1, 0, s, t, "Truncated Ident Packet (length=%d) to 1400 bytes\n", l);
 			l = 1400;
 		}
 		q = makeppp(b, sizeof(b), p, l, t, s, PPPLCP);
 		if (!q)
 		{
-			log(3, session[s].ip, s, t, "Failed to create IdentRej.\n");
+			LOG(3, session[s].ip, s, t, "Failed to create IdentRej.\n");
 			return;
 		}
-		log_hex(5, "LCPIdentRej", q, l + 4);
+		LOG_HEX(5, "LCPIdentRej", q, l + 4);
 		tunnelsend(b, 12 + 4 + l, t);
 	}
 	else
 	{
-		log(1, session[s].ip, s, t, "Unexpected LCP code %d\n", *p);
+		LOG(1, session[s].ip, s, t, "Unexpected LCP code %d\n", *p);
 		STAT(tunnel_rx_errors);
 		return ;
 	}
 }
 
+// find a PPP option, returns point to option, or 0 if not found
+static u8 *findppp(u8 *b, u8 mtype)
+{
+	u16 l = ntohs(*(u16 *) (b + 2));
+	if (l < 4)
+		return 0;
+	b += 4;
+	l -= 4;
+	while (l)
+	{
+		if (l < b[1] || !b[1])
+			return 0;		// faulty
+		if (*b == mtype)
+			return b;
+		l -= b[1];
+		b += b[1];
+	}
+	return 0;
+}
+
 // Process IPCP messages
-void processipcp(tunnelidt t, sessionidt s, u8 * p, u16 l)
+void processipcp(tunnelidt t, sessionidt s, u8 *p, u16 l)
 {
+	u16 hl;
 
 	CSTAT(call_processipcp);
 
-	log_hex(5, "IPCP", p, l);
+	LOG_HEX(5, "IPCP", p, l);
 	if (l < 5)
 	{
-		log(1, 0, s, t, "Short IPCP %d bytes\n", l);
+		LOG(1, 0, s, t, "Short IPCP %d bytes\n", l);
 		STAT(tunnel_rx_errors);
 		return ;
 	}
+
+	if ((hl = ntohs(*(u16 *) (p + 2))) > l)
+	{
+		LOG(1, 0, s, t, "Length mismatch IPCP %u/%u\n", hl, l);
+		STAT(tunnel_rx_errors);
+		return ;
+	}
+	l = hl;
+
 	if (*p == ConfigAck)
 	{
 		// happy with our IPCP
 		u16 r = session[s].radius;
-		if ((!r || radius[r].state == RADIUSIPCP) && !session[s].walled_garden) {
+		if ((!r || radius[r].state == RADIUSIPCP) && !session[s].walled_garden)
+		{
 			if (!r)
 				r = radiusnew(s);
 			if (r)
@@ -518,26 +599,21 @@ void processipcp(tunnelidt t, sessionidt s, u8 * p, u16 l)
 		}
 		session[s].flags |= SF_IPCP_ACKED;
 
-		log(3, session[s].ip, s, t, "IPCP Acked, session is now active\n");
+		LOG(3, session[s].ip, s, t, "IPCP Acked, session is now active\n");
 		return;
 	}
 	if (*p != ConfigReq)
 	{
-		log(1, 0, s, t, "Unexpected IPCP code %d\n", *p);
-		STAT(tunnel_rx_errors);
-		return ;
-	}
-	log(4, session[s].ip, s, t, "IPCP ConfigReq received\n");
-	if (ntohs(*(u16 *) (p + 2)) > l)
-	{
-		log(1, 0, s, t, "Length mismatch IPCP %d/%d\n", ntohs(*(u16 *) (p + 2)), l);
+		LOG(1, 0, s, t, "Unexpected IPCP code %d\n", *p);
 		STAT(tunnel_rx_errors);
 		return ;
 	}
+	LOG(4, session[s].ip, s, t, "IPCP ConfigReq received\n");
+
 	if (!session[s].ip)
 	{
-		log(3, 0, s, t, "Waiting on radius reply\n");
-		return ;                   // have to wait on RADIUS reply
+		LOG(3, 0, s, t, "Waiting on radius reply\n");
+		return;			// have to wait on RADIUS reply
 	}
 	// form a config reply quoting the IP in the session
 	{
@@ -545,7 +621,6 @@ void processipcp(tunnelidt t, sessionidt s, u8 * p, u16 l)
 		u8 *i,
 		*q;
 
-		l = ntohs(*(u16 *) (p + 2)); // We must use length from IPCP len field
 		q = p + 4;
 		i = p + l;
 		while (q < i && q[1])
@@ -561,7 +636,7 @@ void processipcp(tunnelidt t, sessionidt s, u8 * p, u16 l)
 			i = p + l;
 			if (!(q = makeppp(b, sizeof(b), p, l, t, s, PPPIPCP)))
 			{
-				log(2, 0, s, t, "Failed to send IPCP ConfigRej\n");
+				LOG(2, 0, s, t, "Failed to send IPCP ConfigRej\n");
 				return;
 			}
 			*q = ConfigRej;
@@ -570,19 +645,19 @@ void processipcp(tunnelidt t, sessionidt s, u8 * p, u16 l)
 			{
 				if (*p != 0x81 && *p != 0x83 && *p != 3)
 				{
-					log(2, 0, s, t, "IPCP reject %d\n", *p);
+					LOG(2, 0, s, t, "IPCP reject %d\n", *p);
 					memcpy(q + n, p, p[1]);
 					n += p[1];
 				}
 				p += p[1];
 			}
 			*(u16 *) (q + 2) = htons(n);
-			log(4, session[s].ip, s, t, "Sending ConfigRej\n");
+			LOG(4, session[s].ip, s, t, "Sending ConfigRej\n");
 			tunnelsend(b, n + (q - b), t); // send it
 		}
 		else
 		{
-			log(4, session[s].ip, s, t, "Sending ConfigAck\n");
+			LOG(4, session[s].ip, s, t, "Sending ConfigAck\n");
 			*p = ConfigAck;
 			if ((i = findppp(p, 0x81))) // Primary DNS address
 			{
@@ -590,7 +665,7 @@ void processipcp(tunnelidt t, sessionidt s, u8 * p, u16 l)
 				{
 					*(u32 *) (i + 2) = htonl(session[s].dns1);
 					*p = ConfigNak;
-					log(5, session[s].ip, s, t, "   DNS1 = %s\n", inet_toa(session[s].dns1));
+					LOG(5, session[s].ip, s, t, "   DNS1 = %s\n", inet_toa(session[s].dns1));
 				}
 			}
 			if ((i = findppp(p, 0x83))) // Secondary DNS address (TBA, is it)
@@ -599,13 +674,13 @@ void processipcp(tunnelidt t, sessionidt s, u8 * p, u16 l)
 				{
 					*(u32 *) (i + 2) = htonl(session[s].dns2);
 					*p = ConfigNak;
-					log(5, session[s].ip, s, t, "   DNS2 = %s\n", inet_toa(session[s].dns1));
+					LOG(5, session[s].ip, s, t, "   DNS2 = %s\n", inet_toa(session[s].dns2));
 				}
 			}
-			i = findppp(p, 3);   // IP address
+			i = findppp(p, 3);		// IP address
 			if (!i || i[1] != 6)
 			{
-				log(1, 0, s, t, "No IP in IPCP request\n");
+				LOG(1, 0, s, t, "No IP in IPCP request\n");
 				STAT(tunnel_rx_errors);
 				return ;
 			}
@@ -613,12 +688,12 @@ void processipcp(tunnelidt t, sessionidt s, u8 * p, u16 l)
 			{
 				*(u32 *) (i + 2) = htonl(session[s].ip);
 				*p = ConfigNak;
-				log(4, session[s].ip, s, t, " No, a ConfigNak, client is requesting IP - sending %s\n",
-						inet_toa(session[s].ip));
+				LOG(4, session[s].ip, s, t, " No, a ConfigNak, client is requesting IP - sending %s\n",
+						inet_toa(htonl(session[s].ip)));
 			}
 			if (!(q = makeppp(b, sizeof(b), p, l, t, s, PPPIPCP)))
 			{
-				log(2, 0, s, t, " Failed to send IPCP packet.\n");
+				LOG(2, 0, s, t, " Failed to send IPCP packet.\n");
 				return;
 			}
 			tunnelsend(b, l + (q - b), t); // send it
@@ -630,20 +705,19 @@ void processipcp(tunnelidt t, sessionidt s, u8 * p, u16 l)
 //
 // This MUST be called with at least 4 byte behind 'p'.
 // (i.e. this routine writes to p[-4]).
-void processipin(tunnelidt t, sessionidt s, u8 * p, u16 l)
+void processipin(tunnelidt t, sessionidt s, u8 *p, u16 l)
 {
 	ipt ip;
 
-
 	CSTAT(call_processipin);
 
-	log_hex(5, "IP", p, l);
+	LOG_HEX(5, "IP", p, l);
 
 	ip = ntohl(*(u32 *)(p + 12));
 
 	if (l > MAXETHER)
 	{
-		log(1, ip, s, t, "IP packet too long %d\n", l);
+		LOG(1, ip, s, t, "IP packet too long %d\n", l);
 		STAT(tunnel_rx_errors);
 		return ;
 	}
@@ -651,7 +725,7 @@ void processipin(tunnelidt t, sessionidt s, u8 * p, u16 l)
 	// no spoof (do sessionbyip to handled statically routed subnets)
 	if (ip != session[s].ip && sessionbyip(htonl(ip)) != s)
 	{
-		log(5, ip, s, t, "Dropping packet with spoofed IP %s\n", inet_toa(htonl(ip)));
+		LOG(5, ip, s, t, "Dropping packet with spoofed IP %s\n", inet_toa(htonl(ip)));
 		return;
 	}
 
@@ -665,21 +739,6 @@ void processipin(tunnelidt t, sessionidt s, u8 * p, u16 l)
 		return;
 	}
 
-	session[s].cin += l - 4;
-	session[s].total_cin += l - 4;
-	sess_count[s].cin += l - 4;
-
-	session[s].pin++;
-	eth_tx += l - 4;
-
-	if (session[s].snoop_ip && session[s].snoop_port)
-	{
-		// Snooping this session, send it to ASIO
-		snoop_send_packet(p, l, session[s].snoop_ip, session[s].snoop_port);
-	}
-	STAT(tun_tx_packets);
-	INC_STAT(tun_tx_bytes, l);
-
 	if (session[s].tbf_in && config->cluster_iam_master) { // Are we throttled and a master?? actually handle the throttled packets.
 		tbf_queue_packet(session[s].tbf_in, p, l);
 		return;
@@ -689,10 +748,27 @@ void processipin(tunnelidt t, sessionidt s, u8 * p, u16 l)
 	if (tun_write(p, l) < 0)
 	{
 		STAT(tun_tx_errors);
-		log(0, 0, s, t, "Error writing %d bytes to TUN device: %s (tunfd=%d, p=%p)\n",
+		LOG(0, 0, s, t, "Error writing %d bytes to TUN device: %s (tunfd=%d, p=%p)\n",
 			l, strerror(errno), tunfd, p);
+
+		return;
+	}
+
+	if (session[s].snoop_ip && session[s].snoop_port)
+	{
+		// Snooping this session
+		snoop_send_packet(p + 4, l - 4, session[s].snoop_ip, session[s].snoop_port);
 	}
 
+	session[s].cin += l - 4;
+	session[s].total_cin += l - 4;
+	sess_count[s].cin += l - 4;
+
+	session[s].pin++;
+	eth_tx += l - 4;
+
+	STAT(tun_tx_packets);
+	INC_STAT(tun_tx_bytes, l - 4);
 }
 
 //
@@ -701,12 +777,21 @@ void processipin(tunnelidt t, sessionidt s, u8 * p, u16 l)
 //
 void send_ipin(sessionidt s, u8 *buf, int len)
 {
-	log_hex(5, "IP in throttled", buf, len);
+	LOG_HEX(5, "IP in throttled", buf, len);
+
 	if (write(tunfd, buf, len) < 0)
 	{
 		STAT(tun_tx_errors);
-		log(0, 0, 0, 0, "Error writing %d bytes to TUN device: %s (tunfd=%d, p=%p)\n",
+		LOG(0, 0, 0, 0, "Error writing %d bytes to TUN device: %s (tunfd=%d, p=%p)\n",
 			len, strerror(errno), tunfd, buf);
+
+		return;
+	}
+
+	if (session[s].snoop_ip && session[s].snoop_port)
+	{
+		// Snooping this session
+		snoop_send_packet(buf + 4, len - 4, session[s].snoop_ip, session[s].snoop_port);
 	}
 
 	// Increment packet counters
@@ -716,19 +801,22 @@ void send_ipin(sessionidt s, u8 *buf, int len)
 
 	session[s].pin++;
 	eth_tx += len - 4;
+
+	STAT(tun_tx_packets);
+	INC_STAT(tun_tx_bytes, len - 4);
 }
 
 
-// Process LCP messages
-void processccp(tunnelidt t, sessionidt s, u8 * p, u16 l)
+// Process CCP messages
+void processccp(tunnelidt t, sessionidt s, u8 *p, u16 l)
 {
 
 	CSTAT(call_processccp);
 
-	log_hex(5, "CCP", p, l);
+	LOG_HEX(5, "CCP", p, l);
 	if (l < 2 || (*p != ConfigReq && *p != TerminateReq))
 	{
-		log(1, 0, s, t, "Unexpecetd CCP request code %d\n", *p);
+		LOG(1, 0, s, t, "Unexpected CCP request code %d\n", *p);
 		STAT(tunnel_rx_errors);
 		return ;
 	}
@@ -744,15 +832,15 @@ void processccp(tunnelidt t, sessionidt s, u8 * p, u16 l)
 			}
 			else
 			{
-				*p = ConfigRej;        // reject
+				*p = ConfigRej;		// reject
 				sendccp(t, s);
 			}
 		}
 		else
-			*p = TerminateAck;     // close
+			*p = TerminateAck;		// close
 		if (!(q = makeppp(b, sizeof(b), p, l, t, s, PPPCCP)))
 		{
-			log(1,0,0,0, "Failed to send CCP packet.\n");	
+			LOG(1,0,0,0, "Failed to send CCP packet.\n");	
 			return;
 		}
 		tunnelsend(b, l + (q - b), t); // send it
@@ -770,17 +858,18 @@ void sendchap(tunnelidt t, sessionidt s)
 
 	if (!r)
 	{
-		log(1, 0, s, t, "No RADIUS to send challenge\n");
+		LOG(1, 0, s, t, "No RADIUS to send challenge\n");
 		STAT(tunnel_tx_errors);
 		return ;
 	}
-	log(1, 0, s, t, "Send CHAP challenge\n");
-	{                            // new challenge
+	LOG(1, 0, s, t, "Send CHAP challenge\n");
+	{
+		// new challenge
 		int n;
 		for (n = 0; n < 15; n++)
 			radius[r].auth[n] = rand();
 	}
-	radius[r].chap = 1;          // CHAP not PAP
+	radius[r].chap = 1;		// CHAP not PAP
 	radius[r].id++;
 	if (radius[r].state != RADIUSCHAP)
 		radius[r].try = 0;
@@ -793,15 +882,16 @@ void sendchap(tunnelidt t, sessionidt s)
 		return ;
 	}
 	q = makeppp(b, sizeof(b), 0, 0, t, s, PPPCHAP);
-	if (!q) {
-		log(1, 0, s, t, "failed to send CHAP challenge.\n");
+	if (!q)
+	{
+		LOG(1, 0, s, t, "failed to send CHAP challenge.\n");
 		return;
 	}
-	*q = 1;                      // challenhe
-	q[1] = radius[r].id;         // ID
-	q[4] = 16;                   // length
-	memcpy(q + 5, radius[r].auth, 16); // challenge
-	strcpy(q + 21, hostname);    // our name
+	*q = 1;					// challenge
+	q[1] = radius[r].id;			// ID
+	q[4] = 16;				// length
+	memcpy(q + 5, radius[r].auth, 16);	// challenge
+	strcpy(q + 21, hostname);		// our name
 	*(u16 *) (q + 2) = htons(strlen(hostname) + 21); // length
 	tunnelsend(b, strlen(hostname) + 21 + (q - b), t); // send it
 }
@@ -809,9 +899,8 @@ void sendchap(tunnelidt t, sessionidt s)
 // fill in a L2TP message with a PPP frame,
 // copies existing PPP message and changes magic number if seen
 // returns start of PPP frame
-u8 *makeppp(u8 * b, int size, u8 * p, int l, tunnelidt t, sessionidt s, u16 mtype)
+u8 *makeppp(u8 *b, int size, u8 *p, int l, tunnelidt t, sessionidt s, u16 mtype)
 {
-
 	if (size < 12)
 		return NULL;	// Need more space than this!!
 
@@ -819,7 +908,7 @@ u8 *makeppp(u8 * b, int size, u8 * p, int l, tunnelidt t, sessionidt s, u16 mtyp
 	*(u16 *) (b + 2) = htons(tunnel[t].far); // tunnel
 	*(u16 *) (b + 4) = htons(session[s].far); // session
 	b += 6;
-	if (mtype && !(session[s].l2tp_flags & SESSIONACFC))
+	if (mtype == PPPLCP || !(session[s].l2tp_flags & SESSIONACFC))
 	{
 		*(u16 *) b = htons(0xFF03); // HDLC header
 		b += 2;
@@ -833,7 +922,7 @@ u8 *makeppp(u8 * b, int size, u8 * p, int l, tunnelidt t, sessionidt s, u16 mtyp
 	}
 
 	if (l + 12 > size) {
-		log(3,0,0,0, "Would have overflowed the buffer in makeppp: size %d, len %d.\n", size, l);
+		LOG(3,0,0,0, "Would have overflowed the buffer in makeppp: size %d, len %d.\n", size, l);
 		return NULL;	// Run out of room to hold the packet!
 	}
 	if (p && l)
@@ -841,48 +930,32 @@ u8 *makeppp(u8 * b, int size, u8 * p, int l, tunnelidt t, sessionidt s, u16 mtyp
 	return b;
 }
 
-// find a PPP option, returns point to option, or 0 if not found
-u8 *findppp(u8 * b, u8 mtype)
-{
-	u16 l = ntohs(*(u16 *) (b + 2));
-	if (l < 4)
-		return 0;
-	b += 4;
-	l -= 4;
-	while (l)
-	{
-		if (l < b[1] || !b[1])
-			return 0;            // faulty
-		if (*b == mtype)
-			return b;
-		l -= b[1];
-		b += b[1];
-	}
-	return 0;
-}
-
 // Send initial LCP ConfigReq
 void initlcp(tunnelidt t, sessionidt s)
 {
 	char b[500] = {0}, *q;
 
 	q = makeppp(b, sizeof(b), NULL, 0, t, s, PPPLCP);
-	if (!q) {
-		log(1, 0, s, t, "Failed to send LCP ConfigReq.\n");
+	if (!q)
+	{
+		LOG(1, 0, s, t, "Failed to send LCP ConfigReq.\n");
 		return;
 	}
-	log(4, 0, s, t, "Sending LCP ConfigReq for PAP\n");
+	LOG(4, 0, s, t, "Sending LCP ConfigReq for PAP\n");
 	*q = ConfigReq;
 	*(u8 *)(q + 1) = (time_now % 255) + 1; // ID
-	*(u16 *)(q + 2) = htons(8); // Length
-	*(u8 *)(q + 4) = 3;
-	*(u8 *)(q + 5) = 4;
-	*(u16 *)(q + 6) = htons(0xC023); // PAP
-	tunnelsend(b, 12 + 8, t);
+	*(u16 *)(q + 2) = htons(14); // Length
+	*(u8 *)(q + 4) = 5;
+	*(u8 *)(q + 5) = 6;
+	*(u32 *)(q + 6) = htonl(session[s].magic);
+	*(u8 *)(q + 10) = 3;
+	*(u8 *)(q + 11) = 4;
+	*(u16 *)(q + 12) = htons(PPPPAP); // PAP
+	tunnelsend(b, 12 + 14, t);
 }
 
 // Send CCP reply
-void sendccp(tunnelidt t, sessionidt s)
+static void sendccp(tunnelidt t, sessionidt s)
 {
 	char *q, b[500] = {0};
 
@@ -890,7 +963,7 @@ void sendccp(tunnelidt t, sessionidt s)
 	*q = ConfigReq;
 	*(u8 *)(q + 1) = (time_now % 255) + 1; // ID
 	*(u16 *)(q + 2) = htons(4); // Length
-	log_hex(5, "PPPCCP", q, 4);
+	LOG_HEX(5, "PPPCCP", q, 4);
 	tunnelsend(b, (q - b) + 4 , t);
 }