Use more accurate timestamps for scan results

For various P2P use cases, it is useful to have more accurate timestamp
for the peer information update. This commit improves scan result
handling by using a single timestamp that is taken immediately after
fetching the results from the driver and then using that value to
calculate the time when the driver last updated the BSS entry. In
addition, more debug information is added for P2P peer updates to be
able to clearly see how old information is being used here.

Signed-hostap: Jouni Malinen <jouni@qca.qualcomm.com>

src/drivers/driver.h

@@ -187,10 +187,12 @@ struct wpa_scan_res {
  * struct wpa_scan_results - Scan results
  * @res: Array of pointers to allocated variable length scan result entries
  * @num: Number of entries in the scan result array
+ * @fetch_time: Time when the results were fetched from the driver
  */
 struct wpa_scan_results {
 	struct wpa_scan_res **res;
 	size_t num;
+	struct os_time fetch_time;
 };
 
 /**

src/drivers/driver_test.c

@@ -1318,11 +1318,12 @@ static void wpa_driver_test_scan_timeout(void *eloop_ctx, void *timeout_ctx)
 	if (drv->pending_p2p_scan && drv->p2p) {
 #ifdef CONFIG_P2P
 		size_t i;
+		struct os_time now;
+		os_get_time(&now);
 		for (i = 0; i < drv->num_scanres; i++) {
 			struct wpa_scan_res *bss = drv->scanres[i];
 			if (p2p_scan_res_handler(drv->p2p, bss->bssid,
-						 bss->freq, bss->age,
-						 bss->level,
+						 bss->freq, &now, bss->level,
 						 (const u8 *) (bss + 1),
 						 bss->ie_len) > 0)
 				return;

src/p2p/p2p.c

@@ -593,7 +593,7 @@ static void p2p_copy_wps_info(struct p2p_device *dev, int probe_req,
  *	P2P Device Address or P2P Interface Address)
  * @level: Signal level (signal strength of the received frame from the peer)
  * @freq: Frequency on which the Beacon or Probe Response frame was received
- * @age_ms: Age of the information in milliseconds
+ * @rx_time: Time when the result was received
  * @ies: IEs from the Beacon or Probe Response frame
  * @ies_len: Length of ies buffer in octets
  * @scan_res: Whether this was based on scan results
@@ -605,14 +605,14 @@ static void p2p_copy_wps_info(struct p2p_device *dev, int probe_req,
  * Info attributes.
  */
 int p2p_add_device(struct p2p_data *p2p, const u8 *addr, int freq,
-		   unsigned int age_ms, int level, const u8 *ies,
+		   struct os_time *rx_time, int level, const u8 *ies,
 		   size_t ies_len, int scan_res)
 {
 	struct p2p_device *dev;
 	struct p2p_message msg;
 	const u8 *p2p_dev_addr;
 	int i;
-	struct os_time time_now, time_tmp_age, entry_ts;
+	struct os_time time_now;
 
 	os_memset(&msg, 0, sizeof(msg));
 	if (p2p_parse_ies(ies, ies_len, &msg)) {
@@ -649,22 +649,29 @@ int p2p_add_device(struct p2p_data *p2p, const u8 *addr, int freq,
 		return -1;
 	}
 
-	os_get_time(&time_now);
-	time_tmp_age.sec = age_ms / 1000;
-	time_tmp_age.usec = (age_ms % 1000) * 1000;
-	os_time_sub(&time_now, &time_tmp_age, &entry_ts);
+	if (rx_time == NULL) {
+		os_get_time(&time_now);
+		rx_time = &time_now;
+	}
 
 	/*
 	 * Update the device entry only if the new peer
 	 * entry is newer than the one previously stored.
 	 */
-	if (dev->last_seen.usec > 0 &&
-	    os_time_before(&entry_ts, &dev->last_seen)) {
+	if (dev->last_seen.sec > 0 &&
+	    os_time_before(rx_time, &dev->last_seen)) {
+		wpa_msg(p2p->cfg->msg_ctx, MSG_DEBUG, "P2P: Do not update peer "
+			"entry based on old frame (rx_time=%u.%06u "
+			"last_seen=%u.%06u)",
+			(unsigned int) rx_time->sec,
+			(unsigned int) rx_time->usec,
+			(unsigned int) dev->last_seen.sec,
+			(unsigned int) dev->last_seen.usec);
 		p2p_parse_free(&msg);
 		return -1;
 	}
 
-	os_memcpy(&dev->last_seen, &entry_ts, sizeof(struct os_time));
+	os_memcpy(&dev->last_seen, rx_time, sizeof(struct os_time));
 
 	dev->flags &= ~(P2P_DEV_PROBE_REQ_ONLY | P2P_DEV_GROUP_CLIENT_ONLY);
 
@@ -743,7 +750,9 @@ int p2p_add_device(struct p2p_data *p2p, const u8 *addr, int freq,
 		return 0;
 
 	wpa_msg(p2p->cfg->msg_ctx, MSG_DEBUG,
-		"P2P: Peer found with Listen frequency %d MHz", freq);
+		"P2P: Peer found with Listen frequency %d MHz "
+		"(rx_time=%u.%06u)", freq, (unsigned int) rx_time->sec,
+		(unsigned int) rx_time->usec);
 	if (dev->flags & P2P_DEV_USER_REJECTED) {
 		wpa_msg(p2p->cfg->msg_ctx, MSG_DEBUG,
 			"P2P: Do not report rejected device");
@@ -2804,10 +2813,10 @@ static void p2p_prov_disc_cb(struct p2p_data *p2p, int success)
 
 
 int p2p_scan_res_handler(struct p2p_data *p2p, const u8 *bssid, int freq,
-			 unsigned int age, int level, const u8 *ies,
+			 struct os_time *rx_time, int level, const u8 *ies,
 			 size_t ies_len)
 {
-	p2p_add_device(p2p, bssid, freq, age, level, ies, ies_len, 1);
+	p2p_add_device(p2p, bssid, freq, rx_time, level, ies, ies_len, 1);
 
 	return 0;
 }

src/p2p/p2p.h

@@ -1183,7 +1183,7 @@ void p2p_rx_action(struct p2p_data *p2p, const u8 *da, const u8 *sa,
  * @p2p: P2P module context from p2p_init()
  * @bssid: BSSID of the scan result
  * @freq: Frequency of the channel on which the device was found in MHz
- * @age: Age of the scan result in milliseconds
+ * @rx_time: Time when the result was received
  * @level: Signal level (signal strength of the received Beacon/Probe Response
  *	frame)
  * @ies: Pointer to IEs from the scan result
@@ -1205,7 +1205,7 @@ void p2p_rx_action(struct p2p_data *p2p, const u8 *da, const u8 *sa,
  * start of a pending operation, e.g., to start a pending GO negotiation.
  */
 int p2p_scan_res_handler(struct p2p_data *p2p, const u8 *bssid, int freq,
-			 unsigned int age, int level, const u8 *ies,
+			 struct os_time *rx_time, int level, const u8 *ies,
 			 size_t ies_len);
 
 /**

src/p2p/p2p_i.h

@@ -693,7 +693,7 @@ struct p2p_device * p2p_add_dev_from_go_neg_req(struct p2p_data *p2p,
 void p2p_add_dev_info(struct p2p_data *p2p, const u8 *addr,
 		      struct p2p_device *dev, struct p2p_message *msg);
 int p2p_add_device(struct p2p_data *p2p, const u8 *addr, int freq,
-		   unsigned int age_ms, int level, const u8 *ies,
+		   struct os_time *rx_time, int level, const u8 *ies,
 		   size_t ies_len, int scan_res);
 struct p2p_device * p2p_get_device(struct p2p_data *p2p, const u8 *addr);
 struct p2p_device * p2p_get_device_interface(struct p2p_data *p2p,

src/p2p/p2p_invitation.c

@@ -176,7 +176,7 @@ void p2p_process_invitation_req(struct p2p_data *p2p, const u8 *sa,
 			"P2P: Invitation Request from unknown peer "
 			MACSTR, MAC2STR(sa));
 
-		if (p2p_add_device(p2p, sa, rx_freq, 0, 0, data + 1, len - 1,
+		if (p2p_add_device(p2p, sa, rx_freq, NULL, 0, data + 1, len - 1,
 				   0)) {
 			wpa_msg(p2p->cfg->msg_ctx, MSG_DEBUG,
 				"P2P: Invitation Request add device failed "

src/p2p/p2p_pd.c

@@ -152,7 +152,7 @@ void p2p_process_prov_disc_req(struct p2p_data *p2p, const u8 *sa,
 			"P2P: Provision Discovery Request from "
 			"unknown peer " MACSTR, MAC2STR(sa));
 
-		if (p2p_add_device(p2p, sa, rx_freq, 0, 0, data + 1, len - 1,
+		if (p2p_add_device(p2p, sa, rx_freq, NULL, 0, data + 1, len - 1,
 				   0)) {
 			wpa_msg(p2p->cfg->msg_ctx, MSG_DEBUG,
 			        "P2P: Provision Discovery Request add device "

wpa_supplicant/bss.c

@@ -224,7 +224,8 @@ struct wpa_bss * wpa_bss_get(struct wpa_supplicant *wpa_s, const u8 *bssid,
 }
 
 
-static void wpa_bss_copy_res(struct wpa_bss *dst, struct wpa_scan_res *src)
+static void wpa_bss_copy_res(struct wpa_bss *dst, struct wpa_scan_res *src,
+			     struct os_time *fetch_time)
 {
 	os_time_t usec;
 
@@ -238,7 +239,8 @@ static void wpa_bss_copy_res(struct wpa_bss *dst, struct wpa_scan_res *src)
 	dst->level = src->level;
 	dst->tsf = src->tsf;
 
-	os_get_time(&dst->last_update);
+	dst->last_update.sec = fetch_time->sec;
+	dst->last_update.usec = fetch_time->usec;
 	dst->last_update.sec -= src->age / 1000;
 	usec = (src->age % 1000) * 1000;
 	if (dst->last_update.usec < usec) {
@@ -315,7 +317,8 @@ static int wpa_bss_remove_oldest(struct wpa_supplicant *wpa_s)
 
 static struct wpa_bss * wpa_bss_add(struct wpa_supplicant *wpa_s,
 				    const u8 *ssid, size_t ssid_len,
-				    struct wpa_scan_res *res)
+				    struct wpa_scan_res *res,
+				    struct os_time *fetch_time)
 {
 	struct wpa_bss *bss;
 
@@ -324,7 +327,7 @@ static struct wpa_bss * wpa_bss_add(struct wpa_supplicant *wpa_s,
 		return NULL;
 	bss->id = wpa_s->bss_next_id++;
 	bss->last_update_idx = wpa_s->bss_update_idx;
-	wpa_bss_copy_res(bss, res);
+	wpa_bss_copy_res(bss, res, fetch_time);
 	os_memcpy(bss->ssid, ssid, ssid_len);
 	bss->ssid_len = ssid_len;
 	bss->ie_len = res->ie_len;
@@ -480,14 +483,14 @@ static void notify_bss_changes(struct wpa_supplicant *wpa_s, u32 changes,
 
 static struct wpa_bss *
 wpa_bss_update(struct wpa_supplicant *wpa_s, struct wpa_bss *bss,
-	       struct wpa_scan_res *res)
+	       struct wpa_scan_res *res, struct os_time *fetch_time)
 {
 	u32 changes;
 
 	changes = wpa_bss_compare_res(bss, res);
 	bss->scan_miss_count = 0;
 	bss->last_update_idx = wpa_s->bss_update_idx;
-	wpa_bss_copy_res(bss, res);
+	wpa_bss_copy_res(bss, res, fetch_time);
 	/* Move the entry to the end of the list */
 	dl_list_del(&bss->list);
 	if (bss->ie_len + bss->beacon_ie_len >=
@@ -551,13 +554,15 @@ void wpa_bss_update_start(struct wpa_supplicant *wpa_s)
  * wpa_bss_update_scan_res - Update a BSS table entry based on a scan result
  * @wpa_s: Pointer to wpa_supplicant data
  * @res: Scan result
+ * @fetch_time: Time when the result was fetched from the driver
  *
  * This function updates a BSS table entry (or adds one) based on a scan result.
  * This is called separately for each scan result between the calls to
  * wpa_bss_update_start() and wpa_bss_update_end().
  */
 void wpa_bss_update_scan_res(struct wpa_supplicant *wpa_s,
-			     struct wpa_scan_res *res)
+			     struct wpa_scan_res *res,
+			     struct os_time *fetch_time)
 {
 	const u8 *ssid, *p2p;
 	struct wpa_bss *bss;
@@ -595,9 +600,9 @@ void wpa_bss_update_scan_res(struct wpa_supplicant *wpa_s,
 	 * (to save memory) */
 	bss = wpa_bss_get(wpa_s, res->bssid, ssid + 2, ssid[1]);
 	if (bss == NULL)
-		bss = wpa_bss_add(wpa_s, ssid + 2, ssid[1], res);
+		bss = wpa_bss_add(wpa_s, ssid + 2, ssid[1], res, fetch_time);
 	else
-		bss = wpa_bss_update(wpa_s, bss, res);
+		bss = wpa_bss_update(wpa_s, bss, res, fetch_time);
 
 	if (bss == NULL)
 		return;

wpa_supplicant/bss.h

@@ -97,7 +97,8 @@ struct wpa_bss {
 
 void wpa_bss_update_start(struct wpa_supplicant *wpa_s);
 void wpa_bss_update_scan_res(struct wpa_supplicant *wpa_s,
-			     struct wpa_scan_res *res);
+			     struct wpa_scan_res *res,
+			     struct os_time *fetch_time);
 void wpa_bss_update_end(struct wpa_supplicant *wpa_s, struct scan_info *info,
 			int new_scan);
 int wpa_bss_init(struct wpa_supplicant *wpa_s);

wpa_supplicant/p2p_supplicant.c

@@ -106,8 +106,12 @@ static void wpas_p2p_scan_res_handler(struct wpa_supplicant *wpa_s,
 
 	for (i = 0; i < scan_res->num; i++) {
 		struct wpa_scan_res *bss = scan_res->res[i];
+		struct os_time time_tmp_age, entry_ts;
+		time_tmp_age.sec = bss->age / 1000;
+		time_tmp_age.usec = (bss->age % 1000) * 1000;
+		os_time_sub(&scan_res->fetch_time, &time_tmp_age, &entry_ts);
 		if (p2p_scan_res_handler(wpa_s->global->p2p, bss->bssid,
-					 bss->freq, bss->age, bss->level,
+					 bss->freq, &entry_ts, bss->level,
 					 (const u8 *) (bss + 1),
 					 bss->ie_len) > 0)
 			break;

wpa_supplicant/scan.c

@@ -1437,15 +1437,17 @@ static void dump_scan_res(struct wpa_scan_results *scan_res)
 		    == WPA_SCAN_LEVEL_DBM) {
 			int snr = r->level - r->noise;
 			wpa_printf(MSG_EXCESSIVE, MACSTR " freq=%d qual=%d "
-				   "noise=%d level=%d snr=%d%s flags=0x%x",
+				   "noise=%d level=%d snr=%d%s flags=0x%x "
+				   "age=%u",
 				   MAC2STR(r->bssid), r->freq, r->qual,
 				   r->noise, r->level, snr,
-				   snr >= GREAT_SNR ? "*" : "", r->flags);
+				   snr >= GREAT_SNR ? "*" : "", r->flags,
+				   r->age);
 		} else {
 			wpa_printf(MSG_EXCESSIVE, MACSTR " freq=%d qual=%d "
-				   "noise=%d level=%d flags=0x%x",
+				   "noise=%d level=%d flags=0x%x age=%u",
 				   MAC2STR(r->bssid), r->freq, r->qual,
-				   r->noise, r->level, r->flags);
+				   r->noise, r->level, r->flags, r->age);
 		}
 		pos = (u8 *) (r + 1);
 		if (r->ie_len)
@@ -1536,6 +1538,13 @@ wpa_supplicant_get_scan_results(struct wpa_supplicant *wpa_s,
 		wpa_dbg(wpa_s, MSG_DEBUG, "Failed to get scan results");
 		return NULL;
 	}
+	if (scan_res->fetch_time.sec == 0) {
+		/*
+		 * Make sure we have a valid timestamp if the driver wrapper
+		 * does not set this.
+		 */
+		os_get_time(&scan_res->fetch_time);
+	}
 	filter_scan_res(wpa_s, scan_res);
 
 #ifdef CONFIG_WPS
@@ -1552,7 +1561,8 @@ wpa_supplicant_get_scan_results(struct wpa_supplicant *wpa_s,
 
 	wpa_bss_update_start(wpa_s);
 	for (i = 0; i < scan_res->num; i++)
-		wpa_bss_update_scan_res(wpa_s, scan_res->res[i]);
+		wpa_bss_update_scan_res(wpa_s, scan_res->res[i],
+					&scan_res->fetch_time);
 	wpa_bss_update_end(wpa_s, info, new_scan);
 
 	return scan_res;