Merge pull request #359 from nuclearcat/ipcp-ccp-delay-ack

Ipcp ccp delay ack

6 files changed, 238 insertions, 4 deletions

diff --git a/accel-pppd/ppp/ppp_ccp.c b/accel-pppd/ppp/ppp_ccp.c
index 2082ca3f..30ef97b9 100644
--- a/accel-pppd/ppp/ppp_ccp.c
+++ b/accel-pppd/ppp/ppp_ccp.c
@@ -13,6 +13,8 @@
 
 #include "ppp.h"
 #include "ppp_ccp.h"
+#include "ppp_ipcp.h"
+#include "ppp_ipv6cp.h"
 
 #include "memdebug.h"
 
@@ -202,6 +204,9 @@ static void ccp_layer_up(struct ppp_fsm_t *fsm)
 			return;
 		}
 		ppp_layer_started(ccp->ppp, &ccp->ld);
+
+		ipcp_ccp_started(ccp->ppp);
+		ipv6cp_ccp_started(ccp->ppp);
 	}
 }
 
@@ -211,9 +216,12 @@ static void ccp_layer_finished(struct ppp_fsm_t *fsm)
 
 	log_ppp_debug("ccp_layer_finished\n");
 
-	if (!ccp->started)
+	if (!ccp->started) {
 		ppp_layer_passive(ccp->ppp, &ccp->ld);
-	else if (!ccp->ppp->ses.terminating)
+
+		ipcp_ccp_started(ccp->ppp);
+		ipv6cp_ccp_started(ccp->ppp);
+	} else if (!ccp->ppp->ses.terminating)
 		ap_session_terminate(&ccp->ppp->ses, TERM_USER_ERROR, 0);
 
 	fsm->fsm_state = FSM_Closed;
diff --git a/accel-pppd/ppp/ppp_ipcp.c b/accel-pppd/ppp/ppp_ipcp.c
index 2f75542a..1beccf8c 100644
--- a/accel-pppd/ppp/ppp_ipcp.c
+++ b/accel-pppd/ppp/ppp_ipcp.c
@@ -173,6 +173,9 @@ void ipcp_layer_free(struct ppp_layer_data_t *ld)
 	if (ipcp->timeout.tpd)
 		triton_timer_del(&ipcp->timeout);
 
+	if (ipcp->delay_ack_buf)
+		_free(ipcp->delay_ack_buf);
+
 	_free(ipcp);
 }
 
@@ -292,7 +295,11 @@ static void send_conf_ack(struct ppp_fsm_t *fsm)
 	struct ipcp_hdr_t *hdr = (struct ipcp_hdr_t*)ipcp->ppp->buf;
 
 	if (ipcp->delay_ack) {
-		send_term_ack(fsm);
+		/* CCP is still negotiating, withhold the ack until it settles */
+		if (ipcp->delay_ack_buf)
+			_free(ipcp->delay_ack_buf);
+		ipcp->delay_ack_buf = _malloc(ntohs(hdr->len) + 2);
+		memcpy(ipcp->delay_ack_buf, hdr, ntohs(hdr->len) + 2);
 		return;
 	}
 
@@ -812,6 +819,40 @@ int ipcp_option_register(struct ipcp_option_handler_t *h)
 	return 0;
 }
 
+void ipcp_ccp_started(struct ppp_t *ppp)
+{
+	struct ppp_layer_data_t *ld = ppp_find_layer_data(ppp, &ipcp_layer);
+	struct ppp_ipcp_t *ipcp;
+	struct ipcp_hdr_t *hdr;
+
+	if (!ld)
+		return;
+
+	ipcp = container_of(ld, typeof(*ipcp), ld);
+
+	if (!ipcp->delay_ack)
+		return;
+
+	ipcp->delay_ack = 0;
+
+	if (ipcp->fsm.fsm_state == FSM_Opened)
+		__ipcp_layer_up(ipcp);
+
+	if (!ipcp->delay_ack_buf)
+		return;
+
+	hdr = (struct ipcp_hdr_t *)ipcp->delay_ack_buf;
+	hdr->code = CONFACK;
+
+	if (conf_ppp_verbose)
+		log_ppp_info2("send [IPCP ConfAck id=%x]\n", hdr->id);
+
+	ppp_unit_send(ipcp->ppp, hdr, ntohs(hdr->len) + 2);
+
+	_free(ipcp->delay_ack_buf);
+	ipcp->delay_ack_buf = NULL;
+}
+
 struct ipcp_option_t *ipcp_find_option(struct ppp_t *ppp, struct ipcp_option_handler_t *h)
 {
 	struct ppp_ipcp_t *ipcp = container_of(ppp_find_layer_data(ppp, &ipcp_layer), typeof(*ipcp), ld);
diff --git a/accel-pppd/ppp/ppp_ipcp.h b/accel-pppd/ppp/ppp_ipcp.h
index 036f0a4d..8cd7790f 100644
--- a/accel-pppd/ppp/ppp_ipcp.h
+++ b/accel-pppd/ppp/ppp_ipcp.h
@@ -92,12 +92,15 @@ struct ppp_ipcp_t
 	struct list_head ropt_list; // last received ConfReq
 	int ropt_len;
 
+	void *delay_ack_buf; // ConfAck withheld until CCP finishes
+
 	int conf_req_len;
 	unsigned int starting:1;
 	unsigned int started:1;
 	unsigned int delay_ack:1;
 };
 
+void ipcp_ccp_started(struct ppp_t *ppp);
 int ipcp_option_register(struct ipcp_option_handler_t *h);
 struct ipcp_option_t *ipcp_find_option(struct ppp_t *ppp, struct ipcp_option_handler_t *h);
 
diff --git a/accel-pppd/ppp/ppp_ipv6cp.c b/accel-pppd/ppp/ppp_ipv6cp.c
index 370f1d55..3caa89a2 100644
--- a/accel-pppd/ppp/ppp_ipv6cp.c
+++ b/accel-pppd/ppp/ppp_ipv6cp.c
@@ -173,6 +173,9 @@ void ipv6cp_layer_free(struct ppp_layer_data_t *ld)
 	if (ipv6cp->timeout.tpd)
 		triton_timer_del(&ipv6cp->timeout);
 
+	if (ipv6cp->delay_ack_buf)
+		_free(ipv6cp->delay_ack_buf);
+
 	_free(ipv6cp);
 }
 
@@ -296,7 +299,11 @@ static void send_conf_ack(struct ppp_fsm_t *fsm)
 	struct ipv6cp_hdr_t *hdr = (struct ipv6cp_hdr_t*)ipv6cp->ppp->buf;
 
 	if (ipv6cp->delay_ack) {
-		send_term_ack(fsm);
+		/* CCP is still negotiating, withhold the ack until it settles */
+		if (ipv6cp->delay_ack_buf)
+			_free(ipv6cp->delay_ack_buf);
+		ipv6cp->delay_ack_buf = _malloc(ntohs(hdr->len) + 2);
+		memcpy(ipv6cp->delay_ack_buf, hdr, ntohs(hdr->len) + 2);
 		return;
 	}
 
@@ -821,6 +828,40 @@ int ipv6cp_option_register(struct ipv6cp_option_handler_t *h)
 	return 0;
 }
 
+void ipv6cp_ccp_started(struct ppp_t *ppp)
+{
+	struct ppp_layer_data_t *ld = ppp_find_layer_data(ppp, &ipv6cp_layer);
+	struct ppp_ipv6cp_t *ipv6cp;
+	struct ipv6cp_hdr_t *hdr;
+
+	if (!ld)
+		return;
+
+	ipv6cp = container_of(ld, typeof(*ipv6cp), ld);
+
+	if (!ipv6cp->delay_ack)
+		return;
+
+	ipv6cp->delay_ack = 0;
+
+	if (ipv6cp->fsm.fsm_state == FSM_Opened)
+		__ipv6cp_layer_up(ipv6cp);
+
+	if (!ipv6cp->delay_ack_buf)
+		return;
+
+	hdr = (struct ipv6cp_hdr_t *)ipv6cp->delay_ack_buf;
+	hdr->code = CONFACK;
+
+	if (conf_ppp_verbose)
+		log_ppp_info2("send [IPV6CP ConfAck id=%x]\n", hdr->id);
+
+	ppp_unit_send(ipv6cp->ppp, hdr, ntohs(hdr->len) + 2);
+
+	_free(ipv6cp->delay_ack_buf);
+	ipv6cp->delay_ack_buf = NULL;
+}
+
 struct ipv6cp_option_t *ipv6cp_find_option(struct ppp_t *ppp, struct ipv6cp_option_handler_t *h)
 {
 	struct ppp_ipv6cp_t *ipv6cp = container_of(ppp_find_layer_data(ppp, &ipv6cp_layer), typeof(*ipv6cp), ld);
diff --git a/accel-pppd/ppp/ppp_ipv6cp.h b/accel-pppd/ppp/ppp_ipv6cp.h
index 6f1789ec..31bdccf6 100644
--- a/accel-pppd/ppp/ppp_ipv6cp.h
+++ b/accel-pppd/ppp/ppp_ipv6cp.h
@@ -98,12 +98,15 @@ struct ppp_ipv6cp_t
 	struct list_head ropt_list; // last received ConfReq
 	int ropt_len;
 
+	void *delay_ack_buf; // ConfAck withheld until CCP finishes
+
 	int conf_req_len;
 	unsigned int starting:1;
 	unsigned int started:1;
 	unsigned int delay_ack:1;
 };
 
+void ipv6cp_ccp_started(struct ppp_t *ppp);
 int ipv6cp_option_register(struct ipv6cp_option_handler_t *h);
 
 #endif
diff --git a/tests/accel-pppd/pppoe/test_pppoe_ccp_ipcp_race.py b/tests/accel-pppd/pppoe/test_pppoe_ccp_ipcp_race.py
new file mode 100644
index 00000000..d277af63
--- /dev/null
+++ b/tests/accel-pppd/pppoe/test_pppoe_ccp_ipcp_race.py
@@ -0,0 +1,138 @@
+import pytest
+from common import process, config
+import time
+
+
+# accel-pppd log file (separate file, because stdout of accel-pppd is piped
+# by the test harness and is not readable while the test is running)
+@pytest.fixture()
+def accel_pppd_log_file():
+    # test setup:
+    filename = config.make_tmp("")
+
+    # test execution:
+    yield filename
+
+    # test teardown:
+    config.delete_tmp(filename)
+
+
+@pytest.fixture()
+def chap_secrets_config():
+    return "loginRACE     *           pass123   192.0.2.38"
+
+
+# 'mppe=prefer' makes CCP non-passive, so CCP negotiation is still in progress
+# when the peer sends its IPCP ConfReq
+@pytest.fixture()
+def accel_pppd_config(veth_pair_netns, chap_secrets_config_file, accel_pppd_log_file):
+    return (
+        """
+    [modules]
+    log_file
+    chap-secrets
+    pppoe
+    auth_mschap_v2
+
+    [core]
+    log-error=/dev/stderr
+
+    [ppp]
+    verbose=1
+    mppe=prefer
+
+    [log]
+    log-debug="""
+        + accel_pppd_log_file
+        + """
+    log-file=/dev/stdout
+    log-emerg=/dev/stderr
+    level=5
+
+    [cli]
+    tcp=127.0.0.1:2001
+
+    [pppoe]
+    interface="""
+        + veth_pair_netns["veth_a"]
+        + """
+    [chap-secrets]
+    gw-ip-address=192.0.2.1
+    chap-secrets="""
+        + chap_secrets_config_file
+    )
+
+
+# pppd does not require MPPE, so it rejects the MPPE option offered by
+# accel-pppd (which costs CCP an additional round trip) and does not delay
+# IPCP until CCP is done
+@pytest.fixture()
+def pppd_config(veth_pair_netns):
+    return (
+        """
+    nodetach
+    noipdefault
+    noauth
+    persist
+    mtu 1492
+    noaccomp
+    default-asyncmap
+    lcp-echo-interval 0
+    user loginRACE
+    password pass123
+    nic-"""
+        + veth_pair_netns["veth_b"]
+    )
+
+
+# IPCP ConfReq received while CCP is still negotiating must not be answered
+# with a TermAck: the ack is withheld and sent when CCP is done
+@pytest.mark.chap_secrets
+def test_pppoe_ccp_ipcp_race(pppd_instance, accel_cmd, accel_pppd_log_file):
+
+    # test that pppd (with accel-pppd) started successfully
+    assert pppd_instance["is_started"]
+
+    # wait until session is started
+    max_wait_time = 10.0
+    sleep_time = 0.0
+    is_started = False  # is session started
+    while sleep_time < max_wait_time:
+        (exit, out, err) = process.run(
+            [
+                accel_cmd,
+                "show sessions match username log.nRACE username,ip,state",
+            ]
+        )
+        assert exit == 0  # accel-cmd fails
+        if "loginRACE" in out and "192.0.2.38" in out and "active" in out:
+            print("test_pppoe_ccp_ipcp_race: session found in (sec): " + str(sleep_time))
+            is_started = True
+            break
+        time.sleep(0.1)
+        sleep_time += 0.1
+
+    print("test_pppoe_ccp_ipcp_race: last accel-cmd out: " + out)
+
+    # test that session is started
+    assert is_started == True
+
+    with open(accel_pppd_log_file, "r") as f:
+        log = f.read().splitlines()
+    print("test_pppoe_ccp_ipcp_race: accel-pppd log:\n" + "\n".join(log))
+
+    ccp_started = [i for i, line in enumerate(log) if "ccp_layer_started" in line]
+    assert len(ccp_started) > 0  # CCP was negotiated
+
+    # skip if the peer did not send its IPCP ConfReq before CCP was done,
+    # in this case there is nothing to check
+    conf_req = [
+        i
+        for i, line in enumerate(log[: ccp_started[0]])
+        if "recv [IPCP ConfReq" in line
+    ]
+    if len(conf_req) == 0:
+        pytest.skip("peer did not send IPCP ConfReq while CCP was negotiating")
+
+    # test that IPCP ConfReq was not answered with a TermAck
+    assert len([line for line in log if "send [IPCP TermAck" in line]) == 0