wifi: print age of Wi-Fi access point with milliseconds precision

For a computer a second is a really long time. Rounding times
to seconds feels unnecessarily inaccurate.

4 files changed, 31 insertions, 19 deletions

diff --git a/src/devices/wifi/nm-device-iwd.c b/src/devices/wifi/nm-device-iwd.c
index 49fe07fb08..72c83cf0e2 100644
--- a/src/devices/wifi/nm-device-iwd.c
+++ b/src/devices/wifi/nm-device-iwd.c
@@ -101,15 +101,14 @@ static void
 _ap_dump (NMDeviceIwd *self,
           NMLogLevel log_level,
           const NMWifiAP *ap,
-          const char *prefix,
-          gint32 now_s)
+          const char *prefix)
 {
 	char buf[1024];
 
 	buf[0] = '\0';
 	_NMLOG (log_level, LOGD_WIFI_SCAN, "wifi-ap: %-7s %s",
 	        prefix,
-	        nm_wifi_ap_to_string (ap, buf, sizeof (buf), now_s));
+	        nm_wifi_ap_to_string (ap, buf, sizeof (buf), 0));
 }
 
 /* Callers ensure we're not removing current_ap */
@@ -126,12 +125,12 @@ ap_add_remove (NMDeviceIwd *self,
 		ap->wifi_device = NM_DEVICE (self);
 		c_list_link_tail (&priv->aps_lst_head, &ap->aps_lst);
 		nm_dbus_object_export (NM_DBUS_OBJECT (ap));
-		_ap_dump (self, LOGL_DEBUG, ap, "added", 0);
+		_ap_dump (self, LOGL_DEBUG, ap, "added");
 		nm_device_wifi_emit_signal_access_point (NM_DEVICE (self), ap, TRUE);
 	} else {
 		ap->wifi_device = NULL;
 		c_list_unlink (&ap->aps_lst);
-		_ap_dump (self, LOGL_DEBUG, ap, "removed", 0);
+		_ap_dump (self, LOGL_DEBUG, ap, "removed");
 	}
 
 	_notify (self, PROP_ACCESS_POINTS);
@@ -357,7 +356,7 @@ get_ordered_networks_cb (GObject *source, GAsyncResult *res, gpointer user_data)
 		                              nm_wifi_ap_get_supplicant_path (ap));
 		if (new_ap) {
 			if (nm_wifi_ap_set_strength (ap, nm_wifi_ap_get_strength (new_ap))) {
-				_ap_dump (self, LOGL_TRACE, ap, "updated", 0);
+				_ap_dump (self, LOGL_TRACE, ap, "updated");
 				changed = TRUE;
 			}
 			g_hash_table_remove (new_aps,
diff --git a/src/devices/wifi/nm-device-wifi.c b/src/devices/wifi/nm-device-wifi.c
index 889cd39f96..ed9d5c3df8 100644
--- a/src/devices/wifi/nm-device-wifi.c
+++ b/src/devices/wifi/nm-device-wifi.c
@@ -205,14 +205,14 @@ _ap_dump (NMDeviceWifi *self,
           NMLogLevel log_level,
           const NMWifiAP *ap,
           const char *prefix,
-          gint32 now_s)
+          gint64 now_msec)
 {
 	char buf[1024];
 
 	buf[0] = '\0';
 	_NMLOG (log_level, LOGD_WIFI_SCAN, "wifi-ap: %-7s %s",
 	        prefix,
-	        nm_wifi_ap_to_string (ap, buf, sizeof (buf), now_s));
+	        nm_wifi_ap_to_string (ap, buf, sizeof (buf), now_msec));
 }
 
 static void
@@ -1535,14 +1535,21 @@ ap_list_dump (gpointer user_data)
 
 	if (_LOGD_ENABLED (LOGD_WIFI_SCAN)) {
 		NMWifiAP *ap;
-		gint32 now_s = nm_utils_get_monotonic_timestamp_sec ();
-
-		_LOGD (LOGD_WIFI_SCAN, "APs: [now:%u last:%" G_GINT64_FORMAT " next:%u]",
-		       now_s,
-		       priv->last_scan_msec / NM_UTILS_MSEC_PER_SEC,
+		gint64 now_msec = nm_utils_get_monotonic_timestamp_msec ();
+		char str_buf[100];
+
+		_LOGD (LOGD_WIFI_SCAN, "APs: [now:%u.%03u, last:%s, next:%u]",
+		       (guint) (now_msec / NM_UTILS_MSEC_PER_SEC),
+		       (guint) (now_msec % NM_UTILS_MSEC_PER_SEC),
+		         priv->last_scan_msec > 0
+		       ? nm_sprintf_buf (str_buf,
+		                         "%u.%03u",
+		                         (guint) (priv->last_scan_msec / NM_UTILS_MSEC_PER_SEC),
+		                         (guint) (priv->last_scan_msec % NM_UTILS_MSEC_PER_SEC))
+		       : "-1",
 		       priv->scheduled_scan_time);
 		c_list_for_each_entry (ap, &priv->aps_lst_head, aps_lst)
-			_ap_dump (self, LOGL_DEBUG, ap, "dump", now_s);
+			_ap_dump (self, LOGL_DEBUG, ap, "dump", now_msec);
 	}
 	return G_SOURCE_REMOVE;
 }
diff --git a/src/devices/wifi/nm-wifi-ap.c b/src/devices/wifi/nm-wifi-ap.c
index 038d847807..e427c86fbd 100644
--- a/src/devices/wifi/nm-wifi-ap.c
+++ b/src/devices/wifi/nm-wifi-ap.c
@@ -503,13 +503,14 @@ const char *
 nm_wifi_ap_to_string (const NMWifiAP *self,
                       char *str_buf,
                       gulong buf_len,
-                      gint32 now_s)
+                      gint64 now_msec)
 {
 	const NMWifiAPPrivate *priv;
 	const char *supplicant_id = "-";
 	const char *export_path;
 	guint32 chan;
 	gs_free char *ssid_to_free = NULL;
+	char str_buf_ts[100];
 
 	g_return_val_if_fail (NM_IS_WIFI_AP (self), NULL);
 
@@ -525,8 +526,10 @@ nm_wifi_ap_to_string (const NMWifiAP *self,
 	else
 		export_path = "/";
 
+	nm_utils_get_monotonic_timestamp_msec_cached (&now_msec);
+
 	g_snprintf (str_buf, buf_len,
-	            "%17s %-35s [ %c %3u %3u%% %c%c W:%04X R:%04X ] %3us sup:%s [nm:%s]",
+	            "%17s %-35s [ %c %3u %3u%% %c%c W:%04X R:%04X ] %s sup:%s [nm:%s]",
 	            priv->address ?: "(none)",
 	            (ssid_to_free = _nm_utils_ssid_to_string (priv->ssid)),
 	            (priv->mode == NM_802_11_MODE_ADHOC
@@ -545,8 +548,11 @@ nm_wifi_ap_to_string (const NMWifiAP *self,
 	            priv->wpa_flags & 0xFFFF,
 	            priv->rsn_flags & 0xFFFF,
 	              priv->last_seen_msec != G_MININT64
-	            ? (int) ((now_s > 0 ? now_s : nm_utils_get_monotonic_timestamp_sec ()) - (priv->last_seen_msec / 1000))
-	            : -1,
+	            ? nm_sprintf_buf (str_buf_ts,
+	                              "%3u.%03us",
+	                              (guint) ((now_msec - priv->last_seen_msec) / 1000),
+	                              (guint) ((now_msec - priv->last_seen_msec) % 1000))
+	            : "        ",
 	            supplicant_id,
 	            export_path);
 	return str_buf;
diff --git a/src/devices/wifi/nm-wifi-ap.h b/src/devices/wifi/nm-wifi-ap.h
index 2b3864a767..1bf4e604fd 100644
--- a/src/devices/wifi/nm-wifi-ap.h
+++ b/src/devices/wifi/nm-wifi-ap.h
@@ -94,7 +94,7 @@ gboolean          nm_wifi_ap_get_metered              (const NMWifiAP *self);
 const char       *nm_wifi_ap_to_string                (const NMWifiAP *self,
                                                        char *str_buf,
                                                        gulong buf_len,
-                                                       gint32 now_s);
+                                                       gint64 now_msec);
 
 const char      **nm_wifi_aps_get_paths        (const CList *aps_lst_head,
                                                 gboolean include_without_ssid);