Blob Blame History Raw
From 94ba2d701fa93bff69a7bfb1a033f27e53a17439 Mon Sep 17 00:00:00 2001
From: Gris Ge <fge@redhat.com>
Date: Thu, 12 Nov 2020 21:42:01 +0800
Subject: [PATCH] nm provider: Refactor the down action of network connection

When deactivating a profile in libNM, we should:

 * Check `NM.ActionConnection` existence
 * Check `NM.ActionConnection.props.state` not DEACTIVATED
 * Use signal `state-changed` of `NM.ActionConnection`.
 * Only invoke `NM.Client.deactivate_connection_async()` if not
   in DEACTIVATING state.
 * Ignore `NM.ManagerError.CONNECTIONNOTACTIVE` error.

This patch also introduced a new class `NetworkManagerProvider`
in `module_utils/network_lsr/nm`:

 * Independent from Ansible but need to use absolute import due to
   limitation of ansible 2.8.
 * Provide sync function wrapping async calls of libNM.
 * Use stable logging method of python.
 * Only load this module when provider is nm.

This patch also changed how logging is handling in
`Cmd_nm.run_action_down()` as initial step on isolate ansible log
mechanism from provider module.

By moving provider codes to `module_utils` folder, we can eventually
simplify the bloated `library/network_connections.py`.

Signed-off-by: Gris Ge <fge@redhat.com>
---
 library/network_connections.py                | 146 ++++++------------
 module_utils/network_lsr/nm/__init__.py       |   9 ++
 .../network_lsr/nm/active_connection.py       | 125 +++++++++++++++
 module_utils/network_lsr/nm/client.py         |  86 +++++++++++
 module_utils/network_lsr/nm/error.py          |   5 +
 module_utils/network_lsr/nm/provider.py       |  29 ++++
 6 files changed, 300 insertions(+), 100 deletions(-)
 create mode 100644 module_utils/network_lsr/nm/__init__.py
 create mode 100644 module_utils/network_lsr/nm/active_connection.py
 create mode 100644 module_utils/network_lsr/nm/client.py
 create mode 100644 module_utils/network_lsr/nm/error.py
 create mode 100644 module_utils/network_lsr/nm/provider.py

diff --git a/library/network_connections.py b/library/network_connections.py
index e8ee347..e693ab7 100644
--- a/library/network_connections.py
+++ b/library/network_connections.py
@@ -11,6 +11,7 @@ import socket
 import subprocess
 import time
 import traceback
+import logging
 
 # pylint: disable=import-error, no-name-in-module
 from ansible.module_utils.basic import AnsibleModule
@@ -66,6 +67,17 @@ class LogLevel:
     INFO = "info"
     DEBUG = "debug"
 
+    _LOGGING_LEVEL_MAP = {
+        logging.DEBUG: DEBUG,
+        logging.INFO: INFO,
+        logging.WARN: WARN,
+        logging.ERROR: ERROR,
+    }
+
+    @staticmethod
+    def from_logging_level(logging_level):
+        return LogLevel._LOGGING_LEVEL_MAP.get(logging_level, LogLevel.ERROR)
+
     @staticmethod
     def fmt(level):
         return "<%-6s" % (str(level) + ">")
@@ -1386,61 +1398,6 @@ class NMUtil:
         if failure_reason:
             raise MyError("connection not activated: %s" % (failure_reason))
 
-    def active_connection_deactivate(self, ac, timeout=10, wait_time=None):
-        def deactivate_cb(client, result, cb_args):
-            success = False
-            try:
-                success = client.deactivate_connection_finish(result)
-            except Exception as e:
-                if Util.error_is_cancelled(e):
-                    return
-                cb_args["error"] = str(e)
-            cb_args["success"] = success
-            Util.GMainLoop().quit()
-
-        cancellable = Util.create_cancellable()
-        cb_args = {}
-        self.nmclient.deactivate_connection_async(
-            ac, cancellable, deactivate_cb, cb_args
-        )
-        if not Util.GMainLoop_run(timeout):
-            cancellable.cancel()
-            raise MyError("failure to deactivate connection: %s" % (timeout))
-        if not cb_args.get("success", False):
-            raise MyError(
-                "failure to deactivate connection: %s"
-                % (cb_args.get("error", "unknown error"))
-            )
-
-        self.active_connection_deactivate_wait(ac, wait_time)
-        return True
-
-    def active_connection_deactivate_wait(self, ac, wait_time):
-
-        if not wait_time:
-            return
-
-        NM = Util.NM()
-
-        def check_deactivated(ac):
-            return ac.get_state() >= NM.ActiveConnectionState.DEACTIVATED
-
-        if not check_deactivated(ac):
-
-            def check_deactivated_cb():
-                if check_deactivated(ac):
-                    Util.GMainLoop().quit()
-
-            ac_id = ac.connect(
-                "notify::state", lambda source, pspec: check_deactivated_cb()
-            )
-
-            try:
-                if not Util.GMainLoop_run(wait_time):
-                    raise MyError("connection not fully deactivated after timeout")
-            finally:
-                ac.handler_disconnect(ac_id)
-
     def reapply(self, device, connection=None):
         version_id = 0
         flags = 0
@@ -1628,6 +1585,21 @@ class RunEnvironmentAnsible(RunEnvironment):
 ###############################################################################
 
 
+class NmLogHandler(logging.Handler):
+    def __init__(self, log_func, idx):
+        self._log = log_func
+        self._idx = idx
+        super(NmLogHandler, self).__init__()
+
+    def filter(self, record):
+        return True
+
+    def emit(self, record):
+        self._log(
+            self._idx, LogLevel.from_logging_level(record.levelno), record.getMessage()
+        )
+
+
 class Cmd(object):
     def __init__(
         self,
@@ -1953,6 +1925,14 @@ class Cmd_nm(Cmd):
         self._nmutil = None
         self.validate_one_type = ArgValidator_ListConnections.VALIDATE_ONE_MODE_NM
         self._checkpoint = None
+        # pylint: disable=import-error, no-name-in-module
+        from ansible.module_utils.network_lsr.nm import (  # noqa: E501
+            NetworkManagerProvider,
+        )
+
+        # pylint: enable=import-error, no-name-in-module
+
+        self._nm_provider = NetworkManagerProvider()
 
     @property
     def nmutil(self):
@@ -2264,51 +2244,17 @@ class Cmd_nm(Cmd):
 
     def run_action_down(self, idx):
         connection = self.connections[idx]
-
-        cons = self.nmutil.connection_list(name=connection["name"])
-        changed = False
-        if cons:
-            seen = set()
-            while True:
-                ac = Util.first(
-                    self.nmutil.active_connection_list(
-                        connections=cons, black_list=seen
-                    )
-                )
-                if ac is None:
-                    break
-                seen.add(ac)
-                self.log_info(
-                    idx, "down connection %s: %s" % (connection["name"], ac.get_path())
-                )
-                changed = True
-                self.connections_data_set_changed(idx)
-                if self.check_mode == CheckMode.REAL_RUN:
-                    try:
-                        self.nmutil.active_connection_deactivate(ac)
-                    except MyError as e:
-                        self.log_error(idx, "down connection failed: %s" % (e))
-
-                    wait_time = connection["wait"]
-                    if wait_time is None:
-                        wait_time = 10
-
-                    try:
-                        self.nmutil.active_connection_deactivate_wait(ac, wait_time)
-                    except MyError as e:
-                        self.log_error(
-                            idx, "down connection failed while waiting: %s" % (e)
-                        )
-
-                cons = self.nmutil.connection_list(name=connection["name"])
-        if not changed:
-            message = "down connection %s failed: connection not found" % (
-                connection["name"]
-            )
-            if connection[PERSISTENT_STATE] == ABSENT_STATE:
-                self.log_info(idx, message)
-            else:
-                self.log_error(idx, message)
+        logger = logging.getLogger()
+        log_handler = NmLogHandler(self.log, idx)
+        logger.addHandler(log_handler)
+        timeout = connection["wait"]
+        if self._nm_provider.deactivate_connection(
+            connection["name"],
+            10 if timeout is None else timeout,
+            self.check_mode != CheckMode.REAL_RUN,
+        ):
+            self.connections_data_set_changed(idx)
+        logger.removeHandler(log_handler)
 
 
 ###############################################################################
diff --git a/module_utils/network_lsr/nm/__init__.py b/module_utils/network_lsr/nm/__init__.py
new file mode 100644
index 0000000..ce115f8
--- /dev/null
+++ b/module_utils/network_lsr/nm/__init__.py
@@ -0,0 +1,9 @@
+# Relative import is not support by ansible 2.8 yet
+# pylint: disable=import-error, no-name-in-module
+from ansible.module_utils.network_lsr.nm.provider import (  # noqa:E501
+    NetworkManagerProvider,
+)
+
+# pylint: enable=import-error, no-name-in-module
+
+NetworkManagerProvider
diff --git a/module_utils/network_lsr/nm/active_connection.py b/module_utils/network_lsr/nm/active_connection.py
new file mode 100644
index 0000000..451fa61
--- /dev/null
+++ b/module_utils/network_lsr/nm/active_connection.py
@@ -0,0 +1,125 @@
+# SPDX-License-Identifier: BSD-3-Clause
+
+# Handle NM.ActiveConnection
+
+import logging
+
+# Relative import is not support by ansible 2.8 yet
+# pylint: disable=import-error, no-name-in-module
+from ansible.module_utils.network_lsr.nm.client import GLib  # noqa:E501
+from ansible.module_utils.network_lsr.nm.client import NM  # noqa:E501
+from ansible.module_utils.network_lsr.nm.client import get_mainloop  # noqa:E501
+from ansible.module_utils.network_lsr.nm.client import get_client  # noqa:E501
+from ansible.module_utils.network_lsr.nm.error import LsrNetworkNmError  # noqa:E501
+
+# pylint: enable=import-error, no-name-in-module
+
+
+NM_AC_STATE_CHANGED_SIGNAL = "state-changed"
+
+
+def deactivate_active_connection(nm_ac, timeout, check_mode):
+    if not nm_ac or nm_ac.props.state == NM.ActiveConnectionState.DEACTIVATED:
+        logging.info("Connection is not active, no need to deactivate")
+        return False
+    if not check_mode:
+        main_loop = get_mainloop(timeout)
+        logging.debug(
+            "Deactivating {id} with timeout {timeout}".format(
+                id=nm_ac.get_id(), timeout=timeout
+            )
+        )
+        user_data = main_loop
+        handler_id = nm_ac.connect(
+            NM_AC_STATE_CHANGED_SIGNAL, _nm_ac_state_change_callback, user_data
+        )
+        logging.debug(
+            "Registered {signal} on NM.ActiveConnection {id}".format(
+                signal=NM_AC_STATE_CHANGED_SIGNAL, id=nm_ac.get_id()
+            )
+        )
+        if nm_ac.props.state != NM.ActiveConnectionState.DEACTIVATING:
+            nm_client = get_client()
+            user_data = (main_loop, nm_ac, nm_ac.get_id(), handler_id)
+            nm_client.deactivate_connection_async(
+                nm_ac,
+                main_loop.cancellable,
+                _nm_ac_deactivate_call_back,
+                user_data,
+            )
+            logging.debug("Deactivating NM.ActiveConnection {0}".format(nm_ac.get_id()))
+        main_loop.run()
+    return True
+
+
+def _nm_ac_state_change_callback(nm_ac, state, reason, user_data):
+    main_loop = user_data
+    if main_loop.is_cancelled:
+        return
+    logging.debug(
+        "Got NM.ActiveConnection state change: {id}: {state} {reason}".format(
+            id=nm_ac.get_id(), state=state, reason=reason
+        )
+    )
+    if nm_ac.props.state == NM.ActiveConnectionState.DEACTIVATED:
+        logging.debug("NM.ActiveConnection {0} is deactivated".format(nm_ac.get_id()))
+        main_loop.quit()
+
+
+def _nm_ac_deactivate_call_back(nm_client, result, user_data):
+    main_loop, nm_ac, nm_ac_id, handler_id = user_data
+    logging.debug("NM.ActiveConnection deactivating callback")
+    if main_loop.is_cancelled:
+        if nm_ac:
+            nm_ac.handler_disconnect(handler_id)
+        return
+
+    try:
+        success = nm_client.deactivate_connection_finish(result)
+    except GLib.Error as e:
+        if e.matches(NM.ManagerError.quark(), NM.ManagerError.CONNECTIONNOTACTIVE):
+            logging.info(
+                "Connection is not active on {0}, no need to deactivate".format(
+                    nm_ac_id
+                )
+            )
+            if nm_ac:
+                nm_ac.handler_disconnect(handler_id)
+            main_loop.quit()
+            return
+        else:
+            _deactivate_fail(
+                main_loop,
+                handler_id,
+                nm_ac,
+                "Failed to deactivate connection {id}, error={error}".format(
+                    id=nm_ac_id, error=e
+                ),
+            )
+            return
+    except Exception as e:
+        _deactivate_fail(
+            main_loop,
+            handler_id,
+            nm_ac,
+            "Failed to deactivate connection {id}, error={error}".format(
+                id=nm_ac_id, error=e
+            ),
+        )
+        return
+
+    if not success:
+        _deactivate_fail(
+            main_loop,
+            handler_id,
+            nm_ac,
+            "Failed to deactivate connection {0}, error='None "
+            "returned from deactivate_connection_finish()'".format(nm_ac_id),
+        )
+
+
+def _deactivate_fail(main_loop, handler_id, nm_ac, msg):
+    if nm_ac:
+        nm_ac.handler_disconnect(handler_id)
+    logging.error(msg)
+    main_loop.fail(LsrNetworkNmError(msg))
diff --git a/module_utils/network_lsr/nm/client.py b/module_utils/network_lsr/nm/client.py
new file mode 100644
index 0000000..a3c4f98
--- /dev/null
+++ b/module_utils/network_lsr/nm/client.py
@@ -0,0 +1,86 @@
+# SPDX-License-Identifier: BSD-3-Clause
+
+import logging
+
+# Relative import is not support by ansible 2.8 yet
+# pylint: disable=import-error, no-name-in-module
+from ansible.module_utils.network_lsr.nm.error import LsrNetworkNmError  # noqa:E501
+
+import gi
+
+gi.require_version("NM", "1.0")
+
+# It is required to state the NM version before importing it
+# But this break the flake8 rule: https://www.flake8rules.com/rules/E402.html
+# Use NOQA: E402 to suppress it.
+from gi.repository import NM  # NOQA: E402
+from gi.repository import GLib  # NOQA: E402
+from gi.repository import Gio  # NOQA: E402
+
+# pylint: enable=import-error, no-name-in-module
+
+NM
+GLib
+Gio
+
+
+def get_client():
+    return NM.Client.new()
+
+
+class _NmMainLoop(object):
+    def __init__(self, timeout):
+        self._mainloop = GLib.MainLoop()
+        self._cancellable = Gio.Cancellable.new()
+        self._timeout = timeout
+        self._timeout_id = None
+
+    def run(self):
+        logging.debug("NM mainloop running")
+        user_data = None
+        self._timeout_id = GLib.timeout_add(
+            int(self._timeout * 1000),
+            self._timeout_call_back,
+            user_data,
+        )
+        logging.debug("Added timeout checker")
+        self._mainloop.run()
+
+    def _timeout_call_back(self, _user_data):
+        logging.error("Timeout")
+        self.fail(LsrNetworkNmError("Timeout"))
+
+    @property
+    def cancellable(self):
+        return self._cancellable
+
+    @property
+    def is_cancelled(self):
+        if self._cancellable:
+            return self._cancellable.is_cancelled()
+        return True
+
+    def _clean_up(self):
+        logging.debug("NM mainloop cleaning up")
+        if self._timeout_id:
+            logging.debug("Removing timeout checker")
+            GLib.source_remove(self._timeout_id)
+            self._timeout_id = None
+        if self._cancellable:
+            logging.debug("Canceling all pending tasks")
+            self._cancellable.cancel()
+            self._cancellable = None
+        self._mainloop = None
+
+    def quit(self):
+        logging.debug("NM mainloop quiting")
+        self._mainloop.quit()
+        self._clean_up()
+
+    def fail(self, exception):
+        self.quit()
+        raise exception
+
+
+def get_mainloop(timeout):
+    return _NmMainLoop(timeout)
diff --git a/module_utils/network_lsr/nm/error.py b/module_utils/network_lsr/nm/error.py
new file mode 100644
index 0000000..42014ec
--- /dev/null
+++ b/module_utils/network_lsr/nm/error.py
@@ -0,0 +1,5 @@
+# SPDX-License-Identifier: BSD-3-Clause
+
+
+class LsrNetworkNmError(Exception):
+    pass
diff --git a/module_utils/network_lsr/nm/provider.py b/module_utils/network_lsr/nm/provider.py
new file mode 100644
index 0000000..cb703a4
--- /dev/null
+++ b/module_utils/network_lsr/nm/provider.py
@@ -0,0 +1,29 @@
+# SPDX-License-Identifier: BSD-3-Clause
+
+import logging
+
+# Relative import is not support by ansible 2.8 yet
+# pylint: disable=import-error, no-name-in-module
+from ansible.module_utils.network_lsr.nm.active_connection import (  # noqa:E501
+    deactivate_active_connection,
+)
+from ansible.module_utils.network_lsr.nm.client import get_client  # noqa:E501
+
+# pylint: enable=import-error, no-name-in-module
+
+
+class NetworkManagerProvider:
+    def deactivate_connection(self, connection_name, timeout, check_mode):
+        """
+        Return True if changed.
+        """
+        nm_client = get_client()
+        changed = False
+        for nm_ac in nm_client.get_active_connections():
+            nm_profile = nm_ac.get_connection()
+            if nm_profile and nm_profile.get_id() == connection_name:
+                changed |= deactivate_active_connection(nm_ac, timeout, check_mode)
+        if not changed:
+            logging.info("No active connection for {0}".format(connection_name))
+
+        return changed
-- 
2.25.4