allow - in filter names; include in "show session" output
[l2tpns.git] / ppp.c
diff --git a/ppp.c b/ppp.c
index 21d9a21..d44ed25 100644 (file)
--- a/ppp.c
+++ b/ppp.c
@@ -1,6 +1,6 @@
 // L2TPNS PPP Stuff
 
-char const *cvs_id_ppp = "$Id: ppp.c,v 1.18 2004-11-03 13:22:39 bodea Exp $";
+char const *cvs_id_ppp = "$Id: ppp.c,v 1.31 2004-11-27 05:19:53 bodea Exp $";
 
 #include <stdio.h>
 #include <string.h>
@@ -21,9 +21,9 @@ extern int tunfd;
 extern char hostname[];
 extern u32 eth_tx;
 extern time_t time_now;
-extern struct configt *config;
+extern configt *config;
 
-void sendccp(tunnelidt t, sessionidt s);
+static void initccp(tunnelidt t, sessionidt s);
 
 // Process PAP messages
 void processpap(tunnelidt t, sessionidt s, u8 *p, u16 l)
@@ -34,17 +34,17 @@ void processpap(tunnelidt t, sessionidt s, u8 *p, u16 l)
 
        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 ((hl = ntohs(*(u16 *) (p + 2))) > l)
        {
-               log(1, 0, s, t, "Length mismatch PAP %u/%u\n", hl, l);
+               LOG(1, 0, s, t, "Length mismatch PAP %u/%u\n", hl, l);
                STAT(tunnel_rx_errors);
                return ;
        }
@@ -52,7 +52,7 @@ void processpap(tunnelidt t, sessionidt s, u8 *p, u16 l)
 
        if (*p != 1)
        {
-               log(1, 0, s, t, "Unexpected PAP code %d\n", *p);
+               LOG(1, 0, s, t, "Unexpected PAP code %d\n", *p);
                STAT(tunnel_rx_errors);
                return ;
        }
@@ -67,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)
        {
@@ -75,10 +75,8 @@ void processpap(tunnelidt t, sessionidt s, u8 *p, u16 l)
                u8 b[MAXCONTROL];
                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");
-                       return;
-               }
+               if (!p) return;
+
                if (session[s].ip)
                        *p = 2;                 // ACK
                else
@@ -88,14 +86,14 @@ void processpap(tunnelidt t, sessionidt s, u8 *p, u16 l)
                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
@@ -108,7 +106,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;
@@ -121,7 +119,7 @@ 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);
        }
 }
@@ -134,11 +132,11 @@ void processchap(tunnelidt t, sessionidt s, u8 *p, u16 l)
 
        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.
 
@@ -148,14 +146,14 @@ void processchap(tunnelidt t, sessionidt s, u8 *p, u16 l)
 
        if (l < 4)
        {
-               log(1, 0, s, t, "Short CHAP %u bytes\n", l);
+               LOG(1, 0, s, t, "Short CHAP %u bytes\n", l);
                STAT(tunnel_rx_errors);
                return ;
        }
 
        if ((hl = ntohs(*(u16 *) (p + 2))) > l)
        {
-               log(1, 0, s, t, "Length mismatch CHAP %u/%u\n", hl, l);
+               LOG(1, 0, s, t, "Length mismatch CHAP %u/%u\n", hl, l);
                STAT(tunnel_rx_errors);
                return ;
        }
@@ -163,20 +161,20 @@ void processchap(tunnelidt t, sessionidt s, u8 *p, u16 l)
 
        if (*p != 2)
        {
-               log(1, 0, s, t, "Unexpected CHAP response code %d\n", *p);
+               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, "Wrong CHAP response ID %d (should be %d) (%d)\n", p[1], radius[r].id, r);
+               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 (l < 5 || p[4] != 16)
        {
-               log(1, 0, s, t, "Bad CHAP response length %d\n", l < 5 ? -1 : p[4]);
+               LOG(1, 0, s, t, "Bad CHAP response length %d\n", l < 5 ? -1 : p[4]);
                STAT(tunnel_rx_errors);
                return ;
        }
@@ -185,7 +183,7 @@ void processchap(tunnelidt t, sessionidt s, u8 *p, u16 l)
        p += 5;
        if (l < 16 || l - 16 >= sizeof(session[s].user))
        {
-               log(1, 0, s, t, "CHAP user too long %d\n", l - 16);
+               LOG(1, 0, s, t, "CHAP user too long %d\n", l - 16);
                STAT(tunnel_rx_errors);
                return ;
        }
@@ -194,15 +192,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(l - 16 + 1, 1);
-               packet.password = calloc(16, 1);
-               memcpy(packet.username, p + 16, l - 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;
@@ -216,11 +218,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",
@@ -236,14 +238,14 @@ char *ppp_lcp_types[] = {
        "IdentRequest",
 };
 
-void dumplcp(u8 *p, int l)
+static void dumplcp(u8 *p, int l)
 {
        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;
 
@@ -253,12 +255,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;
@@ -267,52 +269,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;
+                                       int proto = ntohs(*(u16 *)(o + 2));
+                                       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;
+                                       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;
                        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;
@@ -330,17 +331,17 @@ void processlcp(tunnelidt t, sessionidt s, u8 *p, u16 l)
 
        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);
+               LOG(1, 0, s, t, "Length mismatch LCP %u/%u\n", hl, l);
                STAT(tunnel_rx_errors);
                return ;
        }
@@ -348,132 +349,151 @@ void processlcp(tunnelidt t, sessionidt s, u8 *p, u16 l)
 
        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)
        {
                int x = l - 4;
                u8 *o = (p + 4);
+               u8 response = 0;
 
-               log(3, session[s].ip, s, t, "LCP: ConfigReq (%d bytes)...\n", 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), NULL, 0, t, s, PPPLCP);
+                                               if (!q) break;
+                                               response = *q++ = ConfigNak;
+                                       }
+
+                                       if ((q - b + 11) > sizeof(b))
+                                       {
+                                               LOG(2, session[s].ip, s, t, "LCP overflow for asyncmap ConfigNak.\n");
+                                               break;
+                                       }
+
+                                       *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)
+                                               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)
                                                {
-                                                       log(2, session[s].ip, s, t, "    Remote end is trying to do CHAP. Rejecting it.\n");
-
-                                                       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;
-                                                       }
-                                                       memcpy(q, o, length);
-                                                       *(u16 *)(q += 2) = htons(0xC023); // NAK -> Use PAP instead
-                                                       q += length;
+                                                       q = makeppp(b, sizeof(b), NULL, 0, t, s, PPPLCP);
+                                                       if (!q) break;
+                                                       response = *q++ = ConfigNak;
                                                }
-                                               break;
+
+                                               if ((q - b + length) > sizeof(b))
+                                               {
+                                                       LOG(2, session[s].ip, s, t, "LCP overflow for %s ConfigNak.\n", proto_name);
+                                                       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;
+
+                               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), NULL, 0, t, s, PPPLCP);
+                                               if (!q) return;
+                                               response = *q++ = ConfigRej;
+                                       }
+
+                                       if ((q - b + length) > sizeof(b))
+                                       {
+                                               LOG(2, session[s].ip, s, t, "LCP overflow for ConfigRej (type=%d).\n", type);
                                                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;
                                        }
 
-                               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");
-                       // for win2k L2TP clients and LCP renegotiation of alive session
-                       if (magicno || l == 4 || (session[s].mru && l == 8)) initlcp(t, s);
                        q = makeppp(b, sizeof(b), p, l, t, s, PPPLCP);
-                       if (!q)
-                       {
-                               log(3, session[s].ip, s, t, " failed to create packet.\n");
-                               return;
-                       }
-                       *q = ConfigAck;
-                       tunnelsend(b, l + (q - b), t);
-               }
-               else
-               {
-                       // Already built a ConfigNak... send it
-                       log(3, session[s].ip, s, t, "Sending ConfigNak\n");
-                       tunnelsend(b, l + (q - b), t);
+                       if (!q) return;
+                       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");
+               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)
        {
+               LOG(3, session[s].ip, s, t, "LCP: Received TerminateReq.  Sending TerminateAck\n");
                *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");
-                       return;
-               }
-               log(3, session[s].ip, s, t, "LCP: Received TerminateReq. Sending TerminateAck\n");
-               sessionshutdown(s, "Remote end closed connection.");
+               if (!q) return;
                tunnelsend(b, l + (q - b), t); // send it
+               sessionshutdown(s, "Remote end closed connection.");
        }
        else if (*p == TerminateAck)
        {
@@ -481,14 +501,11 @@ void processlcp(tunnelidt t, sessionidt s, u8 *p, u16 l)
        }
        else if (*p == EchoReq)
        {
+               LOG(5, session[s].ip, s, t, "LCP: Received EchoReq.  Sending EchoReply\n");
                *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");
-                       return;
-               }
-               log(5, session[s].ip, s, t, "LCP: Received EchoReq. Sending EchoReply\n");
+               if (!q) return;
                tunnelsend(b, l + (q - b), t); // send it
        }
        else if (*p == EchoReply)
@@ -500,26 +517,42 @@ 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");
-                       return;
-               }
-               log_hex(5, "LCPIdentRej", q, l + 4);
+               if (!q) return;
+               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)
 {
@@ -527,17 +560,17 @@ void processipcp(tunnelidt t, sessionidt s, u8 *p, u16 l)
 
        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);
+               LOG(1, 0, s, t, "Length mismatch IPCP %u/%u\n", hl, l);
                STAT(tunnel_rx_errors);
                return ;
        }
@@ -556,20 +589,24 @@ 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");
+
+               // clear LCP_ACKED/CCP_ACKED flag for possible fast renegotiaion for routers
+               session[s].flags &= ~(SF_LCP_ACKED|SF_CCP_ACKED);
+
                return;
        }
        if (*p != ConfigReq)
        {
-               log(1, 0, s, t, "Unexpected IPCP code %d\n", *p);
+               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");
+       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");
+               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
@@ -592,29 +629,27 @@ void processipcp(tunnelidt t, sessionidt s, u8 *p, u16 l)
                        u16 n = 4;
                        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");
                                return;
-                       }
+
                        *q = ConfigRej;
                        p += 4;
                        while (p < i && p[1])
                        {
                                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
                        {
@@ -622,7 +657,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)
@@ -631,13 +666,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
                        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 ;
                        }
@@ -645,14 +680,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",
+                               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");
                                return;
-                       }
+
                        tunnelsend(b, l + (q - b), t); // send it
                }
        }
@@ -668,13 +701,13 @@ void processipin(tunnelidt t, sessionidt s, u8 *p, u16 l)
 
        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 ;
        }
@@ -682,7 +715,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;
        }
 
@@ -696,21 +729,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
-               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;
@@ -720,10 +738,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);
 }
 
 //
@@ -732,12 +767,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
@@ -747,47 +791,61 @@ 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
+// Process CCP messages
 void processccp(tunnelidt t, sessionidt s, u8 *p, u16 l)
 {
+       u8 b[MAXCONTROL];
+       u8 *q;
 
        CSTAT(call_processccp);
 
-       log_hex(5, "CCP", p, l);
-       if (l < 2 || (*p != ConfigReq && *p != TerminateReq))
+       LOG_HEX(5, "CCP", p, l);
+       switch (l > 1 ? *p : 0)
        {
-               log(1, 0, s, t, "Unexpected CCP request code %d\n", *p);
-               STAT(tunnel_rx_errors);
-               return ;
-       }
-       // reject
-       {
-               u8 b[MAXCONTROL];
-               u8 *q;
-               if (*p == ConfigReq)
+       case ConfigAck:
+               session[s].flags |= SF_CCP_ACKED;
+               return;
+
+       case ConfigReq:
+               if (l < 6) // accept no compression
                {
-                       if (l < 6)
-                       {
-                               *p = ConfigAck;         // accept no compression
-                       }
-                       else
-                       {
-                               *p = ConfigRej;         // reject
-                               sendccp(t, s);
-                       }
+                       *p = ConfigAck;
+                       break;
                }
+
+               // compression requested--reject
+               *p = ConfigRej;
+
+               // send CCP request for no compression for our end if not negotiated
+               if (!(session[s].flags & SF_CCP_ACKED))
+                       initccp(t, s);
+
+               break;
+
+       case TerminateReq:
+               *p = TerminateAck;
+               break;
+
+       default:
+               if (l > 1)
+                       LOG(1, 0, s, t, "Unexpected CCP request code %d\n", *p);
                else
-                       *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");   
-                       return;
-               }
-               tunnelsend(b, l + (q - b), t); // send it
+                       LOG(1, 0, s, t, "Short CCP packet\n");
+
+               STAT(tunnel_rx_errors);
+               return;
        }
+
+       if (!(q = makeppp(b, sizeof(b), p, l, t, s, PPPCCP)))
+               return;
+
+       tunnelsend(b, l + (q - b), t); // send it
 }
 
 // send a CHAP PP packet
@@ -801,11 +859,11 @@ 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");
+       LOG(1, 0, s, t, "Send CHAP challenge\n");
        {
                // new challenge
                int n;
@@ -825,10 +883,8 @@ 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");
-               return;
-       }
+       if (!q) return;
+
        *q = 1;                                 // challenge
        q[1] = radius[r].id;                    // ID
        q[4] = 16;                              // length
@@ -843,8 +899,13 @@ void sendchap(tunnelidt t, sessionidt s)
 // returns start of PPP frame
 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!!
+       if (size < 12) // Need more space than this!!
+       {
+               static int backtrace_count = 0;
+               LOG(0, session[s].ip, s, t, "makeppp buffer too small for L2TP header (size=%d)\n", size);
+               log_backtrace(backtrace_count, 5)
+               return NULL;
+       }
 
        *(u16 *) (b + 0) = htons(0x0002); // L2TP with no options
        *(u16 *) (b + 2) = htons(tunnel[t].far); // tunnel
@@ -863,46 +924,29 @@ u8 *makeppp(u8 *b, int size, u8 *p, int l, tunnelidt t, sessionidt s, u16 mtype)
                b += 2;
        }
 
-       if (l + 12 > size) {
-               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 (l + 12 > size)
+       {
+               static int backtrace_count = 0;
+               LOG(2, session[s].ip, s, t, "makeppp would overflow buffer (size=%d, header+payload=%d)\n", size, l + 12);
+               log_backtrace(backtrace_count, 5)
+               return NULL;
        }
+
        if (p && l)
                memcpy(b, p, l);
-       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;
+       return b;
 }
 
-// Send initial LCP ConfigReq
+// Send initial LCP ConfigReq for PAP, set magic no.
 void initlcp(tunnelidt t, sessionidt s)
 {
-       char b[500] = {0}, *q;
+       char b[500], *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 = makeppp(b, sizeof(b), NULL, 0, t, s, PPPLCP)))
                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(14); // Length
@@ -911,20 +955,25 @@ void initlcp(tunnelidt t, sessionidt s)
        *(u32 *)(q + 6) = htonl(session[s].magic);
        *(u8 *)(q + 10) = 3;
        *(u8 *)(q + 11) = 4;
-       *(u16 *)(q + 12) = htons(0xC023); // PAP
-       tunnelsend(b, 12 + 14, t);
+       *(u16 *)(q + 12) = htons(PPPPAP); // PAP
+
+       LOG_HEX(5, "PPPLCP", q, 14);
+       tunnelsend(b, (q - b) + 14, t);
 }
 
-// Send CCP reply
-void sendccp(tunnelidt t, sessionidt s)
+// Send CCP request for no compression
+static void initccp(tunnelidt t, sessionidt s)
 {
-       char *q, b[500] = {0};
+       char b[500], *q;
+
+       if (!(q = makeppp(b, sizeof(b), NULL, 0, t, s, PPPCCP)))
+               return;
 
-       q = makeppp(b, sizeof(b), NULL, 0, t, s, PPPCCP);
+       LOG(4, 0, s, t, "Sending CCP ConfigReq for no compression\n");
        *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);
 }
-