datastorage/ubus: rework kicking algorithm

Refresh of kicking algorithm to minimise messages and streamline some code.
Removed decide_function() which made some logic hard to follow.
Removed kick_client() function to streamline code.
Revised kicking algorithm code to give better user messages.

Signed-off-by: Ian Clowes <clowes_ian@hotmail.com>

src/storage/datastorage.c

@@ -21,8 +21,6 @@ struct local_config_s local_config;
 
 static int probe_compare(probe_entry *probe1, probe_entry *probe2);
 
-static int kick_client(ap* kicking_ap, struct client_s *client_entry, struct kicking_nr** neighbor_report);
-
 static int is_connected(struct dawn_mac bssid_mac, struct dawn_mac client_mac);
 
 static int compare_station_count(ap* ap_entry_own, ap* ap_entry_to_compare, struct dawn_mac client_addr);
@@ -599,7 +597,8 @@ int better_ap_available(ap *kicking_ap, struct dawn_mac client_mac, struct kicki
 
     int max_score = own_score;
     int kick = 0;
-    // Now carry on through entries for this client looking for better score
+    int ap_count = 0;
+    // Now go through all AP entries for this client looking for better score
     probe_entry* i = *probe_array_find_first_entry(client_mac, dawn_mac_null, false);
 
     while (i != NULL && mac_is_equal_bb(i->client_addr, client_mac)) {
@@ -624,66 +623,74 @@ int better_ap_available(ap *kicking_ap, struct dawn_mac client_mac, struct kicki
             continue;
         }
 
-        dawnlog_debug("Calculating score to compare!\n");
+        ap_count++;
+
         int score_to_compare = eval_probe_metric(i, candidate_ap);
+        dawnlog_trace("Candidate score = %d from:\n", score_to_compare);
+        print_probe_entry(DAWNLOG_TRACE, i);
+
+        int ap_outcome = 0; // No kicking
 
         // Find better score...
+        // FIXME: Do we mean to use 'kick' like this here?  It is set when we find an AP with bigger score
+        // then any more have to also be 'kicking_threshold' bigger
         if (score_to_compare > max_score + (kick ? 0 : dawn_metric.kicking_threshold)) {
-            if(neighbor_report == NULL)
+            ap_outcome = 2; // Add and prune
-            {
-                dawnlog_error("Neighbor-Report is NULL!\n");
-                return 1;  // TODO: Should this be -1?
-            }
-
-            kick = 1;
-
-            // instead of returning we add the ap to the neighbor report list, pruning it first...
-            *neighbor_report = insert_kicking_nr(*neighbor_report, candidate_ap->neighbor_report, score_to_compare, true);
 
             max_score = score_to_compare;
         }
-        // if ap have same value but station count is different...
+        // if AP have same value but station count might improve it...
         // TODO: Is absolute number meaningful when AP have diffeent capacity?
-        else if (dawn_metric.use_station_count > 0 && score_to_compare >= max_score ) {
+        else if (score_to_compare == max_score && dawn_metric.use_station_count > 0 ) {
             int compare = compare_station_count(kicking_ap, candidate_ap, client_mac);
 
             if (compare > 0) {
-                if (neighbor_report == NULL)
+                ap_outcome = 2; // Add and prune
-                {
-                    dawnlog_error( "Neighbor-Report is NULL!\n");
-                    return 1;  // TODO: Should this be -1?
-                }
-
-                kick = 1;
-                *neighbor_report = insert_kicking_nr(*neighbor_report, candidate_ap->neighbor_report,
-                                                     score_to_compare, true);
             }
             else if (compare == 0 && kick) {
-                *neighbor_report = insert_kicking_nr(*neighbor_report, candidate_ap->neighbor_report,
+                ap_outcome = 1; // Add but no prune
-                                                     score_to_compare, false);
             }
         }
         else if (score_to_compare >= max_score && kick) {
-            *neighbor_report = insert_kicking_nr(*neighbor_report, candidate_ap->neighbor_report,
+            ap_outcome = 1; // Add but no prune
-                                                 score_to_compare, false);
         }
 
-        i = i->next_probe;
+        if (ap_outcome == 0)
+        {
+            dawnlog_trace("Not a better AP after full evaluation\n");
+        }
+        else
+        {
+            dawnlog_trace("Better AP after full evaluation - add to NR (%s pruning)\n", ap_outcome == 2 ? "with" : "without");
+            // Pointer is NULL if we're only finding a better AP without actually using it
+            if (neighbor_report != NULL)
+            {
+                // Test this_kick_outcome for pruning
+                *neighbor_report = insert_kicking_nr(*neighbor_report, candidate_ap->neighbor_report,
+                    score_to_compare, ap_outcome == 2);
+            }
+
+            // If we find a single candidate then we will be kicking
+            kick = 1;
+        }
+
+        // Short circuit loop if we're only finding a better AP without actually using it
+        if (kick && neighbor_report == NULL)
+        {
+            i = NULL;
+        }
+        else
+        {
+            i = i->next_probe;
+        }
     }
 
+    if (neighbor_report != NULL)
+        dawnlog_info("Station " MACSTR ": Compared %d alternate AP candidates\n", MAC2STR(client_mac.u8), ap_count);
+
     return kick;
 }
 
-static int kick_client(ap* kicking_ap, struct client_s *client_entry, struct kicking_nr** neighbor_report) {
-    int ret = 0;
-
-    if (!mac_in_maclist(client_entry->client_addr)) {
-        ret = better_ap_available(kicking_ap, client_entry->client_addr, neighbor_report);
-    }
-
-    return ret;
-}
-
 int kick_clients(ap* kicking_ap, uint32_t id) {
     dawnlog_debug_func("Entering...");
 
@@ -701,9 +708,14 @@ int kick_clients(ap* kicking_ap, uint32_t id) {
     while (j  != NULL && mac_is_equal_bb(j->bssid_addr, kicking_ap->bssid_addr)) {
         struct kicking_nr *neighbor_report = NULL;
 
-        int do_kick = kick_client(kicking_ap, j, &neighbor_report);
+        int do_kick = 0;
-        for (struct kicking_nr *n = neighbor_report; n; n = n->next)
+
-           dawnlog_debug("Chosen AP candidate: " NR_MACSTR ", score=%d\n", NR_MAC2STR(n->nr), n->score);
+        if (mac_in_maclist(j->client_addr)) {
+            dawnlog_info("Station " MACSTR ": Suppressing check due to MAC list entry\n", MAC2STR(j->client_addr.u8));
+        }
+        else {
+            do_kick = better_ap_available(kicking_ap, j->client_addr, &neighbor_report);
+        }
 
         // better ap available
         if (do_kick > 0) {
@@ -713,17 +725,15 @@ int kick_clients(ap* kicking_ap, uint32_t id) {
             // + chan util is changing a lot
             // + ping pong behavior of clients will be reduced
             j->kick_count++;
-           dawnlog_debug("Comparing kick count! kickcount: %d to min_number_to_kick: %d!\n", j->kick_count,
+            if (j->kick_count < dawn_metric.min_number_to_kick) {
-                dawn_metric.min_number_to_kick);
+                dawnlog_info("Station " MACSTR ": kickcount %d below threshold of %d!\n", MAC2STR(j->client_addr.u8), j->kick_count,
-            if (j->kick_count >= dawn_metric.min_number_to_kick) {
+                    dawn_metric.min_number_to_kick);
-               dawnlog_debug("Better AP available. Kicking client:\n");
+            }
-                print_client_entry(DAWNLOG_DEBUG, j);
+            else {
-               dawnlog_debug("Check if client is active receiving!\n");
-
                 float rx_rate, tx_rate;
                 bool have_bandwidth_iwinfo = get_bandwidth_iwinfo(j->client_addr, &rx_rate, &tx_rate);
                 if (!have_bandwidth_iwinfo && dawn_metric.bandwidth_threshold > 0) {
-                   dawnlog_debug("No active transmission data for client. Don't kick!\n");
+                    dawnlog_info("Station " MACSTR ": No active transmission data for client. Don't kick!\n", MAC2STR(j->client_addr.u8));
                 }
                 else
                 {
@@ -770,8 +780,6 @@ int kick_clients(ap* kicking_ap, uint32_t id) {
                             // don't delete clients in a row. use update function again...
                             // -> chan_util update, ...
                             add_client_update_timer(timeout_config.update_client * 1000 / 4);
-                            remove_kicking_nr_list(neighbor_report);
-                            neighbor_report = NULL;
                             break;
                         }
                     }
@@ -795,6 +803,7 @@ int kick_clients(ap* kicking_ap, uint32_t id) {
 
         remove_kicking_nr_list(neighbor_report);
         neighbor_report = NULL;
+
         j = j->next_entry_bc;
     }
 

src/utils/ubus.c

@@ -243,38 +243,6 @@ void blobmsg_add_macaddr(struct blob_buf *buf, const char *name, const struct da
     blobmsg_add_string_buffer(buf);
 }
 
-// TODO: Is it worth having this function?  Just inline the right bits at each caller?
-static int decide_function(probe_entry *prob_req, int req_type) {
-    if (mac_in_maclist(prob_req->client_addr)) {
-        return 1;
-    }
-
-    if (prob_req->counter < dawn_metric.min_probe_count) {
-        return 0;
-    }
-
-    if (req_type == REQ_TYPE_PROBE && dawn_metric.eval_probe_req <= 0) {
-        return 1;
-    }
-
-    if (req_type == REQ_TYPE_AUTH && dawn_metric.eval_auth_req <= 0) {
-        return 1;
-    }
-
-    if (req_type == REQ_TYPE_ASSOC && dawn_metric.eval_assoc_req <= 0) {
-        return 1;
-    }
-
-    // TODO: Bug?  This results in copious "Neigbor-Report is NULL" messages!
-    // find own probe entry and calculate score
-    ap* this_ap = ap_array_get_ap(prob_req->bssid_addr, prob_req->ssid);
-    if (this_ap != NULL && better_ap_available(this_ap, prob_req->client_addr, NULL)) {
-        return 0;
-    }
-
-    return 1;
-}
-
 int parse_to_auth_req(struct blob_attr *msg, auth_entry *auth_req) {
     struct blob_attr *tb[__AUTH_MAX];
 
@@ -401,7 +369,7 @@ bool discard_entry = true;
     if (auth_req == NULL)
     {
         dawnlog_error("Memory allocation of auth req failed!");
-        return -1;
+        return ret; // Allow if we can't evalute a reason to deny
     }
 
     parse_to_auth_req(msg, auth_req);
@@ -409,15 +377,55 @@ bool discard_entry = true;
     dawnlog_debug("Auth entry: ");
     print_auth_entry(DAWNLOG_DEBUG, auth_req);
 
-    if (!mac_in_maclist(auth_req->client_addr)) {
+    if (dawn_metric.eval_auth_req <= 0) {
+        dawnlog_trace("Allow authentication due to not evaluating requests");
+    }
+    else if (mac_in_maclist(auth_req->client_addr)) {
+        dawnlog_trace("Allow authentication due to mac_in_maclist()");
+    }
+    else {
         pthread_mutex_lock(&probe_array_mutex);
 
+        if (dawnlog_showing(DAWNLOG_DEBUG))
+            print_probe_array();
+
         probe_entry *tmp = probe_array_get_entry(auth_req->bssid_addr, auth_req->client_addr);
 
         pthread_mutex_unlock(&probe_array_mutex);
 
+        /*** Deprecated function decide_function() removed here ***/
+        int deny_request = 0;
+        
         // block if entry was not already found in probe database
-        if (tmp == NULL || !decide_function(tmp, REQ_TYPE_AUTH)) {
+        if (tmp == NULL) {
+            dawnlog_trace("Deny authentication due to no probe entry");
+            deny_request = 1;
+        }
+#if 0
+        // Already know this is false from outer test above
+        else if (mac_in_maclist(probe_req_updated->client_addr)) {
+            dawnlog_trace("Short cut due to mac_in_maclist()");
+        }
+#endif
+        else if (tmp->counter < dawn_metric.min_probe_count) {
+            dawnlog_trace("Deny authentication due to low probe count");
+            deny_request = 1;
+        }
+        else
+        {
+            // find own probe entry and calculate score
+            ap* this_ap = ap_array_get_ap(tmp->bssid_addr, tmp->ssid);
+            if (this_ap != NULL && better_ap_available(this_ap, tmp->client_addr, NULL) > 0) {
+                dawnlog_trace("Deny authentication due to better AP available");
+                deny_request = 1;
+            }
+            else
+                // maybe send here that the client is connected?
+                dawnlog_trace("Allow authentication!\n");
+        }
+        /*** End of decide_function() rework ***/
+
+        if (deny_request) {
             if (dawn_metric.use_driver_recog) {
                 if (auth_req == insert_to_denied_req_array(auth_req, 1, time(0)))
                     discard_entry = false;
@@ -440,29 +448,73 @@ int ret = WLAN_STATUS_SUCCESS;
 int discard_entry = true;
 
     dawnlog_debug_func("Entering...");
-    print_probe_array();
+
     auth_entry* assoc_req = dawn_malloc(sizeof(struct auth_entry_s));
     if (assoc_req == NULL)
-        return -1;
+    {
+        dawnlog_error("Memory allocation of assoc req failed!");
+        return ret; // Allow if we can't evalute a reason to deny
+    }
 
     parse_to_assoc_req(msg, assoc_req);
     dawnlog_debug("Association entry: ");
     print_auth_entry(DAWNLOG_DEBUG, assoc_req);
 
-    if (!mac_in_maclist(assoc_req->client_addr)) {
+    if (dawn_metric.eval_assoc_req <= 0) {
+        dawnlog_trace("Allow association due to not evaluating requests");
+    }
+    else if (mac_in_maclist(assoc_req->client_addr)) {
+        dawnlog_trace("Allow association due to mac_in_maclist()");
+    } else {
         pthread_mutex_lock(&probe_array_mutex);
 
+        if (dawnlog_showing(DAWNLOG_DEBUG))
+            print_probe_array();
+
         probe_entry *tmp = probe_array_get_entry(assoc_req->bssid_addr, assoc_req->client_addr);
 
         pthread_mutex_unlock(&probe_array_mutex);
 
+        /*** Deprecated function decide_function() removed here ***/
+        int deny_request = 0;
+        
         // block if entry was not already found in probe database
-        if (tmp == NULL || !decide_function(tmp, REQ_TYPE_ASSOC)) {
+        if (tmp == NULL) {
+            dawnlog_trace("Deny association due to no probe entry found");
+            deny_request = 1;
+        }
+#if 0
+        // Already know this is false from outer test above
+        else if (mac_in_maclist(tmp->client_addr)) {
+            dawnlog_trace("Allow due to mac_in_maclist()");
+        }
+#endif
+        else if (tmp->counter < dawn_metric.min_probe_count) {
+            dawnlog_trace("Deny association due to low probe count");
+            deny_request = 1;
+        }
+        else
+        {
+            // find own probe entry and calculate score
+            ap* this_ap = ap_array_get_ap(tmp->bssid_addr, tmp->ssid);
+            if (this_ap != NULL && better_ap_available(this_ap, tmp->client_addr, NULL) > 0) {
+                dawnlog_trace("Deny association due to better AP available");
+                deny_request = 1;
+            }
+            else
+                dawnlog_trace("Allow association!\n");
+        }
+        /*** End of decide_function() rework ***/
+
+        if (deny_request) {
+            if (tmp != NULL)
+                print_probe_entry(DAWNLOG_DEBUG, tmp);
+
             if (dawn_metric.use_driver_recog) {
                 if (assoc_req == insert_to_denied_req_array(assoc_req, 1, time(0)))
                     discard_entry = false;
             }
-            return dawn_metric.deny_assoc_reason;
+            ret = dawn_metric.deny_assoc_reason;
         }
     }
 
@@ -475,14 +527,21 @@ int discard_entry = true;
     return ret;
 }
 
-static int handle_probe_req(struct blob_attr *msg) {
+static int handle_probe_req(struct blob_attr* msg) {
     // MUSTDO: Untangle dawn_malloc() and linking of probe_entry
     probe_entry* probe_req = parse_to_probe_req(msg);
-    probe_entry* probe_req_updated = NULL;
+
     dawnlog_debug_func("Entering...");
 
-    if (probe_req != NULL) {
+
-        probe_req_updated = insert_to_array(probe_req, true, true, false, time(0));
+    if (probe_req == NULL)
+    {
+        dawnlog_error("Parse of probe req failed!");
+        return WLAN_STATUS_SUCCESS; // Allow if we can't evalute a reason to deny
+    }
+    else
+    {
+        probe_entry* probe_req_updated = insert_to_array(probe_req, true, true, false, time(0));
         // If insert finds an existing entry, rather than linking in our new one,
         // send new probe req because we want to stay synced.
         // If not, probe_req and probe_req_updated should be equivalent
@@ -494,7 +553,35 @@ static int handle_probe_req(struct blob_attr *msg) {
 
         ubus_send_probe_via_network(probe_req_updated);
 
-        if (!decide_function(probe_req_updated, REQ_TYPE_PROBE)) {
+        /*** Deprecated function decide_function() removed here ***/
+        int deny_request = 0;
+
+        if (dawn_metric.eval_probe_req <= 0) {
+            dawnlog_trace("Allow probe due to not evaluating requests");
+        }
+        else if (mac_in_maclist(probe_req_updated->client_addr)) {
+            dawnlog_trace("Allow probe due to mac_in_maclist()");
+        }
+        else if (probe_req_updated->counter < dawn_metric.min_probe_count) {
+            dawnlog_trace("Deny probe due to low probe count");
+            deny_request = 1;
+        }
+        else
+        {
+            // find own probe entry and calculate score
+            ap* this_ap = ap_array_get_ap(probe_req_updated->bssid_addr, probe_req_updated->ssid);
+            if (this_ap != NULL && better_ap_available(this_ap, probe_req_updated->client_addr, NULL) > 0) {
+                dawnlog_trace("Deny probe due to better AP available");
+                deny_request = 1;
+            }
+            else
+            {
+                dawnlog_trace("Allow probe request!");
+            }
+        }
+        /*** End of decide_function() rework ***/
+
+        if (deny_request) {
             return WLAN_STATUS_AP_UNABLE_TO_HANDLE_NEW_STA; // no reason needed...
         }
     }