core: improve logging why startup-complete is blocked

Before:

    "manager: check_if_startup_complete returns FALSE because of eth0"

Now:

    "manager: startup complete is waiting for device 'eth0' (autoactivate)"

Also, the logging line is now more a human readable sentence, but still
follows the same pattern as later

    "manager: startup complete"

Meaning: grepping for "startup complete" becomes more helpful because
one first finds the reasons why startup-complete is not yet reached,
followed by the moment when it is reached.

5 files changed, 48 insertions, 23 deletions

diff --git a/src/devices/nm-device.c b/src/devices/nm-device.c
index 6347e292b3..9b9bf9d55c 100644
--- a/src/devices/nm-device.c
+++ b/src/devices/nm-device.c
@@ -13991,22 +13991,22 @@ nm_device_remove_pending_action (NMDevice *self, const char *action, gboolean as
 	return FALSE;
 }
 
-gboolean
-nm_device_has_pending_action (NMDevice *self)
+const char *
+nm_device_has_pending_action_reason (NMDevice *self)
 {
 	NMDevicePrivate *priv = NM_DEVICE_GET_PRIVATE (self);
 
 	if (priv->pending_actions)
-		return TRUE;
+		return priv->pending_actions->data;
 
 	if (   nm_device_is_real (self)
 	    && nm_device_get_unmanaged_flags (self, NM_UNMANAGED_PLATFORM_INIT)) {
 		/* as long as the platform link is not yet initialized, we have a pending
 		 * action. */
-		return TRUE;
+		return NM_PENDING_ACTION_LINK_INIT;
 	}
 
-	return FALSE;
+	return NULL;
 }
 
 /*****************************************************************************/
diff --git a/src/devices/nm-device.h b/src/devices/nm-device.h
index 0f7252fdf2..056d1c9cab 100644
--- a/src/devices/nm-device.h
+++ b/src/devices/nm-device.h
@@ -76,6 +76,7 @@ nm_device_state_reason_check (NMDeviceStateReason reason)
 #define NM_PENDING_ACTION_WAITING_FOR_SUPPLICANT    "waiting-for-supplicant"
 #define NM_PENDING_ACTION_WIFI_SCAN                 "wifi-scan"
 #define NM_PENDING_ACTION_WAITING_FOR_COMPANION     "waiting-for-companion"
+#define NM_PENDING_ACTION_LINK_INIT                 "link-init"
 
 #define NM_PENDING_ACTIONPREFIX_QUEUED_STATE_CHANGE "queued-state-change-"
 #define NM_PENDING_ACTIONPREFIX_ACTIVATION          "activation-"
@@ -748,7 +749,13 @@ gboolean nm_device_supports_vlans (NMDevice *device);
 
 gboolean nm_device_add_pending_action    (NMDevice *device, const char *action, gboolean assert_not_yet_pending);
 gboolean nm_device_remove_pending_action (NMDevice *device, const char *action, gboolean assert_is_pending);
-gboolean nm_device_has_pending_action    (NMDevice *device);
+const char *nm_device_has_pending_action_reason (NMDevice *device);
+
+static inline gboolean
+nm_device_has_pending_action (NMDevice *device)
+{
+	return !!nm_device_has_pending_action_reason (device);
+}
 
 NMSettingsConnection *nm_device_get_best_connection (NMDevice *device,
                                                      const char *specific_object,
diff --git a/src/nm-manager.c b/src/nm-manager.c
index 267fd2e2a0..27d7c5ad98 100644
--- a/src/nm-manager.c
+++ b/src/nm-manager.c
@@ -1518,6 +1518,7 @@ check_if_startup_complete (NMManager *self)
 {
 	NMManagerPrivate *priv = NM_MANAGER_GET_PRIVATE (self);
 	NMDevice *device;
+	const char *reason;
 
 	if (!priv->startup)
 		return;
@@ -1525,15 +1526,19 @@ check_if_startup_complete (NMManager *self)
 	if (!priv->devices_inited)
 		return;
 
-	if (!nm_settings_get_startup_complete (priv->settings)) {
-		_LOGD (LOGD_CORE, "check_if_startup_complete returns FALSE because of NMSettings");
+	reason = nm_settings_get_startup_complete_blocked_reason (priv->settings);
+	if (reason) {
+		_LOGD (LOGD_CORE, "startup complete is waiting for connection (%s)",
+		       reason);
 		return;
 	}
 
 	c_list_for_each_entry (device, &priv->devices_lst_head, devices_lst) {
-		if (nm_device_has_pending_action (device)) {
-			_LOGD (LOGD_CORE, "check_if_startup_complete returns FALSE because of %s",
-			       nm_device_get_iface (device));
+		reason = nm_device_has_pending_action_reason (device);
+		if (reason) {
+			_LOGD (LOGD_CORE, "startup complete is waiting for device '%s' (%s)",
+			       nm_device_get_iface (device),
+			       reason);
 			return;
 		}
 	}
diff --git a/src/settings/nm-settings.c b/src/settings/nm-settings.c
index 2253d56a84..29a943b0ed 100644
--- a/src/settings/nm-settings.c
+++ b/src/settings/nm-settings.c
@@ -129,6 +129,8 @@ typedef struct {
 
 	NMHostnameManager *hostname_manager;
 
+	NMSettingsConnection *startup_complete_blocked_by;
+
 	guint connections_len;
 
 	bool started:1;
@@ -182,19 +184,23 @@ static void
 check_startup_complete (NMSettings *self)
 {
 	NMSettingsPrivate *priv = NM_SETTINGS_GET_PRIVATE (self);
-	NMSettingsConnection *conn;
+	NMSettingsConnection *sett_conn;
 
 	if (priv->startup_complete)
 		return;
 
-	c_list_for_each_entry (conn, &priv->connections_lst_head, _connections_lst) {
-		if (!nm_settings_connection_get_ready (conn))
+	c_list_for_each_entry (sett_conn, &priv->connections_lst_head, _connections_lst) {
+		if (!nm_settings_connection_get_ready (sett_conn)) {
+			nm_g_object_ref_set (&priv->startup_complete_blocked_by, sett_conn);
 			return;
+		}
 	}
 
+	g_clear_object (&priv->startup_complete_blocked_by);
+
 	/* the connection_ready_changed signal handler is no longer needed. */
-	c_list_for_each_entry (conn, &priv->connections_lst_head, _connections_lst)
-		g_signal_handlers_disconnect_by_func (conn, G_CALLBACK (connection_ready_changed), self);
+	c_list_for_each_entry (sett_conn, &priv->connections_lst_head, _connections_lst)
+		g_signal_handlers_disconnect_by_func (sett_conn, G_CALLBACK (connection_ready_changed), self);
 
 	priv->startup_complete = TRUE;
 	_notify (self, PROP_STARTUP_COMPLETE);
@@ -840,10 +846,10 @@ connection_removed (NMSettingsConnection *connection, gpointer user_data)
 	if (priv->connections_loaded)
 		g_signal_emit (self, signals[CONNECTION_REMOVED], 0, connection);
 
-	g_object_unref (connection);
-
 	check_startup_complete (self);
 
+	g_object_unref (connection);
+
 	g_object_unref (self);       /* Balanced by a ref in claim_connection() */
 }
 
@@ -1754,12 +1760,17 @@ nm_settings_device_removed (NMSettings *self, NMDevice *device, gboolean quittin
 
 /*****************************************************************************/
 
-gboolean
-nm_settings_get_startup_complete (NMSettings *self)
+const char *
+nm_settings_get_startup_complete_blocked_reason (NMSettings *self)
 {
 	NMSettingsPrivate *priv = NM_SETTINGS_GET_PRIVATE (self);
+	const char *uuid = NULL;
 
-	return priv->startup_complete;
+	if (priv->startup_complete)
+		return NULL;
+	if (priv->startup_complete_blocked_by)
+		uuid = nm_settings_connection_get_uuid (priv->startup_complete_blocked_by);
+	return uuid ?: "unknown";
 }
 
 /*****************************************************************************/
@@ -1845,7 +1856,7 @@ get_property (GObject *object, guint prop_id,
 			g_value_set_boxed (value, NULL);
 		break;
 	case PROP_STARTUP_COMPLETE:
-		g_value_set_boolean (value, nm_settings_get_startup_complete (self));
+		g_value_set_boolean (value, !nm_settings_get_startup_complete_blocked_reason (self));
 		break;
 	default:
 		G_OBJECT_WARN_INVALID_PROPERTY_ID (object, prop_id, pspec);
@@ -1878,6 +1889,8 @@ dispose (GObject *object)
 	NMSettings *self = NM_SETTINGS (object);
 	NMSettingsPrivate *priv = NM_SETTINGS_GET_PRIVATE (self);
 
+	g_clear_object (&priv->startup_complete_blocked_by);
+
 	g_slist_free_full (priv->auths, (GDestroyNotify) nm_auth_chain_destroy);
 	priv->auths = NULL;
 
diff --git a/src/settings/nm-settings.h b/src/settings/nm-settings.h
index 38d8ad4ed8..eb74c09c4a 100644
--- a/src/settings/nm-settings.h
+++ b/src/settings/nm-settings.h
@@ -112,6 +112,6 @@ void nm_settings_device_added (NMSettings *self, NMDevice *device);
 
 void nm_settings_device_removed (NMSettings *self, NMDevice *device, gboolean quitting);
 
-gboolean nm_settings_get_startup_complete (NMSettings *self);
+const char *nm_settings_get_startup_complete_blocked_reason (NMSettings *self);
 
 #endif  /* __NM_SETTINGS_H__ */