dhcp: call synchronous Notify D-Bus method from nm-dhcp-helper

A D-Bus signal is asynchronous and it can happen that nm-dhcp-helper
emits the "Event" signal before the server is able to register a handler:

   NM_DHCP_HELPER=/usr/libexec/nm-dhcp-helper
   nmcli general logging level TRACE
   for i in `seq 1 500`; do $NM_DHCP_HELPER & done
   journalctl -u NetworkManager --since '1 min ago' | grep "didn't have associated interface" | wc -l
    499

Avoid that, by calling the synchronous D-Bus method "Notify".

Interestingly, this race seem to exist since 2007.

Actually, we called g_dbus_connection_signal_subscribe() from inside
GDBusServer:new-connection signal. So it is not clear how such a race
could exist. I was not able to reproduce it by putting a sleep
before g_dbus_connection_signal_subscribe(). On the other hand, there
is bug rh#1372854 and above reproducer which strongly indicates that
events can be lost under certain circumstances.
Now we instead g_dbus_connection_register_object() from the
new-connection signal. According to my tests there was no more race
as also backed by glib's documentation. Still, keep a simple retry-loop
in nm-dhcp-helper just to be sure.

https://bugzilla.redhat.com/show_bug.cgi?id=1372854
https://bugzilla.redhat.com/show_bug.cgi?id=1373276
(cherry picked from commit 2856a658b3)
This commit is contained in:
Thomas Haller 2016-09-05 12:32:40 +02:00
parent 3ac3125aff
commit e678bd29a4
4 changed files with 153 additions and 33 deletions

View file

@ -26,6 +26,11 @@
#define NM_DHCP_CLIENT_DBUS_IFACE "org.freedesktop.nm_dhcp_client"
#define NM_DHCP_HELPER_SERVER_BUS_NAME "org.freedesktop.nm_dhcp_server"
#define NM_DHCP_HELPER_SERVER_OBJECT_PATH "/org/freedesktop/nm_dhcp_server"
#define NM_DHCP_HELPER_SERVER_INTERFACE_NAME "org.freedesktop.nm_dhcp_server"
#define NM_DHCP_HELPER_SERVER_METHOD_NOTIFY "Notify"
/******************************************************************************/
#endif /* __NM_DHCP_HELPER_API_H__ */

View file

@ -105,7 +105,7 @@ build_signal_parameters (void)
g_free (name);
}
return g_variant_new ("(a{sv})", &builder);
return g_variant_ref_sink (g_variant_new ("(a{sv})", &builder));
}
static void
@ -128,7 +128,11 @@ main (int argc, char *argv[])
{
gs_unref_object GDBusConnection *connection = NULL;
gs_free_error GError *error = NULL;
gs_unref_variant GVariant *parameters = NULL;
gs_unref_variant GVariant *result = NULL;
gboolean success = FALSE;
guint try_count = 0;
gint64 time_end;
nm_g_type_init ();
@ -142,25 +146,73 @@ main (int argc, char *argv[])
goto out;
}
if (!g_dbus_connection_emit_signal (connection,
NULL,
"/",
NM_DHCP_CLIENT_DBUS_IFACE,
"Event",
build_signal_parameters (),
&error)) {
g_dbus_error_strip_remote_error (error);
_LOGE ("could not send DHCP Event signal: %s", error->message);
goto out;
}
parameters = build_signal_parameters ();
time_end = g_get_monotonic_time () + (200 * 1000L); /* retry for at most 200 milliseconds */
do_notify:
try_count++;
result = g_dbus_connection_call_sync (connection,
NULL,
NM_DHCP_HELPER_SERVER_OBJECT_PATH,
NM_DHCP_HELPER_SERVER_INTERFACE_NAME,
NM_DHCP_HELPER_SERVER_METHOD_NOTIFY,
parameters,
NULL,
G_DBUS_CALL_FLAGS_NONE,
1000,
NULL,
&error);
if (!result) {
gs_free char *s_err = NULL;
s_err = g_dbus_error_get_remote_error (error);
if (NM_IN_STRSET (s_err, "org.freedesktop.DBus.Error.UnknownMethod")) {
gint64 remaining_time = time_end - g_get_monotonic_time ();
/* I am not sure that a race can actually happen, as we register the object
* on the server side during GDBusServer:new-connection signal.
*
* However, there was also a race for subscribing to an event, so let's just
* do some retry. */
if (remaining_time > 0) {
_LOGi ("failure to call notify: %s (retry %u)", error->message, try_count);
g_usleep (NM_MIN (NM_CLAMP ((gint64) (100L * (1L << try_count)), 5000, 25000), remaining_time));
g_clear_error (&error);
goto do_notify;
}
}
_LOGW ("failure to call notify: %s (try signal via Event)", error->message);
g_clear_error (&error);
/* for backward compatibilty, try to emit the signal. There is no stable
* API between the dhcp-helper and NetworkManager. However, while upgrading
* the NetworkManager package, a newer helper might want to notify an
* older server, which still uses the "Event". */
if (!g_dbus_connection_emit_signal (connection,
NULL,
"/",
NM_DHCP_CLIENT_DBUS_IFACE,
"Event",
parameters,
&error)) {
g_dbus_error_strip_remote_error (error);
_LOGE ("could not send DHCP Event signal: %s", error->message);
goto out;
}
/* We were able to send the asynchronous Event. Consider that a success. */
success = TRUE;
} else
success = TRUE;
if (!g_dbus_connection_flush_sync (connection, NULL, &error)) {
g_dbus_error_strip_remote_error (error);
_LOGE ("could not flush D-Bus connection: %s", error->message);
success = FALSE;
goto out;
}
success = TRUE;
out:
if (!success)
kill_pid ();

View file

@ -119,13 +119,14 @@ get_option (GVariant *options, const char *key)
}
static void
handle_event (GDBusConnection *connection,
const char *sender_name,
const char *object_path,
const char *interface_name,
const char *signal_name,
GVariant *parameters,
gpointer user_data)
_method_call (GDBusConnection *connection,
const char *sender,
const char *object_path,
const char *interface_name,
const char *method_name,
GVariant *parameters,
GDBusMethodInvocation *invocation,
gpointer user_data)
{
NMDhcpListener *self = NM_DHCP_LISTENER (user_data);
char *iface = NULL;
@ -135,8 +136,12 @@ handle_event (GDBusConnection *connection,
gboolean handled = FALSE;
GVariant *options;
if (!nm_streq0 (interface_name, NM_DHCP_HELPER_SERVER_INTERFACE_NAME))
g_return_if_reached ();
if (!nm_streq0 (method_name, NM_DHCP_HELPER_SERVER_METHOD_NOTIFY))
g_return_if_reached ();
if (!g_variant_is_of_type (parameters, G_VARIANT_TYPE ("(a{sv})")))
return;
g_return_if_reached ();
g_variant_get (parameters, "(@a{sv})", &options);
@ -173,6 +178,57 @@ out:
g_free (pid_str);
g_free (reason);
g_variant_unref (options);
g_dbus_method_invocation_return_value (invocation, NULL);
}
static guint
_dbus_connection_register_object (NMDhcpListener *self,
GDBusConnection *connection,
GError **error)
{
static GDBusArgInfo arg_info_notify_in = {
.ref_count = -1,
.name = "data",
.signature = "a{sv}",
.annotations = NULL,
};
static GDBusArgInfo *arg_infos_notify[] = {
&arg_info_notify_in,
NULL,
};
static GDBusMethodInfo method_info_notify = {
.ref_count = -1,
.name = NM_DHCP_HELPER_SERVER_METHOD_NOTIFY,
.in_args = arg_infos_notify,
.out_args = NULL,
.annotations = NULL,
};
static GDBusMethodInfo *method_infos[] = {
&method_info_notify,
NULL,
};
static GDBusInterfaceInfo interface_info = {
.ref_count = -1,
.name = NM_DHCP_HELPER_SERVER_INTERFACE_NAME,
.methods = method_infos,
.signals = NULL,
.properties = NULL,
.annotations = NULL,
};
static GDBusInterfaceVTable interface_vtable = {
.method_call = _method_call,
.get_property = NULL,
.set_property = NULL,
};
return g_dbus_connection_register_object (connection,
NM_DHCP_HELPER_SERVER_OBJECT_PATH,
&interface_info,
&interface_vtable,
self,
NULL,
error);
}
static void
@ -182,17 +238,20 @@ new_connection_cb (NMBusManager *mgr,
NMDhcpListener *self)
{
NMDhcpListenerPrivate *priv = NM_DHCP_LISTENER_GET_PRIVATE (self);
guint id;
guint registration_id;
GError *error = NULL;
id = g_dbus_connection_signal_subscribe (connection,
NULL,
NM_DHCP_CLIENT_DBUS_IFACE,
"Event",
NULL,
NULL,
G_DBUS_SIGNAL_FLAGS_NONE,
handle_event, self, NULL);
g_hash_table_insert (priv->connections, connection, GUINT_TO_POINTER (id));
/* it is important to register the object during the new-connection signal,
* as this avoids races with the connecting object. */
registration_id = _dbus_connection_register_object (self, connection, &error);
if (!registration_id) {
_LOGE ("failure to register %s for connection %p: %s",
NM_DHCP_HELPER_SERVER_OBJECT_PATH, connection, error->message);
g_error_free (error);
return;
}
g_hash_table_insert (priv->connections, connection, GUINT_TO_POINTER (registration_id));
}
static void
@ -205,7 +264,7 @@ dis_connection_cb (NMBusManager *mgr,
id = GPOINTER_TO_UINT (g_hash_table_lookup (priv->connections, connection));
if (id) {
g_dbus_connection_signal_unsubscribe (connection, id);
g_dbus_connection_unregister_object (connection, id);
g_hash_table_remove (priv->connections, connection);
}
}

View file

@ -221,7 +221,11 @@ private_server_new_connection (GDBusServer *server,
_LOGD ("(%s) accepted connection %p on private socket", s->tag, conn);
/* Emit this for the manager */
/* Emit this for the manager.
*
* It is essential to do this from the "new-connection" signal handler, as
* at that point no messages from the connection are yet processed
* (which avoids races with registering objects). */
g_signal_emit (s->manager,
signals[PRIVATE_CONNECTION_NEW],
s->detail,