[network-manager-openvpn/th/handle-child-process-bgo761299] service: introduce logging macros _LOG_x()

[Thomas Haller <thaller src gnome org>]

commit cad70c723e09bf815381dab152c7d66e313b594a
Author: Thomas Haller <thaller redhat com>
Date:   Sun Jan 31 18:29:43 2016 +0100

    service: introduce logging macros _LOG_x()
    
    Replace the direct calls to g_warning() and g_message() by
    new macros _LOG_x(), where "x" is the logging severity.
    Upper case names like _LOG_W() and _LOG_D() are for unconditional
    logging, while the lower-case macro _LOG_d() only prints the
    message when debugging is enabled.
    
    Also change the glib logging level for debug messages from
    g_message()/G_LOG_LEVEL_MESSAGE to _LOG_D()/G_LOG_LEVEL_INFO.

 src/nm-openvpn-service.c |  110 ++++++++++++++++++++++++++--------------------
 1 files changed, 62 insertions(+), 48 deletions(-)
---
diff --git a/src/nm-openvpn-service.c b/src/nm-openvpn-service.c
index 4f04255..cde74c4 100644
--- a/src/nm-openvpn-service.c
+++ b/src/nm-openvpn-service.c
@@ -57,9 +57,8 @@
 # define DIST_VERSION VERSION
 #endif
 
-static gboolean debug = FALSE;
-
 static struct {
+       gboolean debug;
        GSList *pids_pending_list;
 } gl/*obal*/;
 
@@ -160,6 +159,26 @@ static ValidProperty valid_secrets[] = {
 
 /*****************************************************************************/
 
+#define _LOG(log_always, level, ...) \
+       G_STMT_START { \
+               if ((log_always) || _LOG_d_enabled ()) { \
+                       g_log (G_LOG_DOMAIN, level, __VA_ARGS__); \
+               } \
+       } G_STMT_END
+
+static gboolean
+_LOG_d_enabled (void)
+{
+       return gl.debug;
+}
+
+#define _LOG_d(...) _LOG(FALSE, G_LOG_LEVEL_INFO, __VA_ARGS__)
+#define _LOG_D(...) _LOG(TRUE,  G_LOG_LEVEL_INFO, __VA_ARGS__)
+#define _LOG_I(...) _LOG(TRUE,  G_LOG_LEVEL_MESSAGE, __VA_ARGS__)
+#define _LOG_W(...) _LOG(TRUE,  G_LOG_LEVEL_WARNING, __VA_ARGS__)
+
+/*****************************************************************************/
+
 static void
 pids_pending_data_free (PidsPendingData *pid_data)
 {
@@ -195,16 +214,16 @@ pids_pending_child_watch_cb (GPid pid, gint status, gpointer user_data)
 
                exit_status = WEXITSTATUS (status);
                if (exit_status != 0)
-                       g_warning ("openvpn[%ld] exited with error code %d", (long) pid, exit_status);
+                       _LOG_W ("openvpn[%ld] exited with error code %d", (long) pid, exit_status);
                else
-                       g_message ("openvpn[%ld] exited with success", (long) pid);
+                       _LOG_I ("openvpn[%ld] exited with success", (long) pid);
     }
        else if (WIFSTOPPED (status))
-               g_warning ("openvpn[%ld] stopped unexpectedly with signal %d", (long) pid, WSTOPSIG (status));
+               _LOG_W ("openvpn[%ld] stopped unexpectedly with signal %d", (long) pid, WSTOPSIG (status));
        else if (WIFSIGNALED (status))
-               g_warning ("openvpn[%ld] died with signal %d", (long) pid, WTERMSIG (status));
+               _LOG_W ("openvpn[%ld] died with signal %d", (long) pid, WTERMSIG (status));
        else
-               g_warning ("openvpn[%ld] died from an unnatural cause", (long) pid);
+               _LOG_W ("openvpn[%ld] died from an unnatural cause", (long) pid);
 
        g_return_if_fail (pid_data);
        g_return_if_fail (pid_data->pid == pid);
@@ -228,7 +247,7 @@ pids_pending_add (NMOpenvpnPlugin *plugin, GPid pid)
        g_return_if_fail (NM_IS_OPENVPN_PLUGIN (plugin));
        g_return_if_fail (pid > 0);
 
-       g_message ("openvpn[%ld] started", (long) pid);
+       _LOG_I ("openvpn[%ld] started", (long) pid);
 
        pid_data = g_slice_new (PidsPendingData);
        pid_data->pid = pid;
@@ -247,7 +266,7 @@ pids_pending_ensure_killed (gpointer user_data)
 
        g_return_val_if_fail (pid_data && pid_data == pids_pending_get (pid_data->pid), FALSE);
 
-       g_message ("openvpn[%ld]: send SIGKILL", (long) pid_data->pid);
+       _LOG_I ("openvpn[%ld]: send SIGKILL", (long) pid_data->pid);
 
        pid_data->kill_id = 0;
        kill (pid_data->pid, SIGKILL);
@@ -262,7 +281,7 @@ pids_pending_send_sigterm (GPid pid)
        pid_data = pids_pending_get (pid);
        g_return_if_fail (pid_data);
 
-       g_message ("openvpn[%ld]: send SIGTERM", (long) pid);
+       _LOG_I ("openvpn[%ld]: send SIGTERM", (long) pid);
 
        kill (pid, SIGTERM);
        pid_data->kill_id = g_timeout_add (2000, pids_pending_ensure_killed, pid_data);
@@ -272,7 +291,7 @@ static void
 pids_pending_wait_for_processes (GMainLoop *main_loop)
 {
        if (gl.pids_pending_list) {
-               g_message ("wait for %u openvpn processes to terminate...", g_slist_length 
(gl.pids_pending_list));
+               _LOG_I ("wait for %u openvpn processes to terminate...", g_slist_length 
(gl.pids_pending_list));
 
                do {
                        g_main_context_iteration (g_main_loop_get_context (main_loop), TRUE);
@@ -642,8 +661,7 @@ handle_management_socket (NMOpenvpnPlugin *plugin,
                return TRUE;
        }
 
-       if (debug)
-               g_message ("VPN request '%s'", str);
+       _LOG_d ("VPN request '%s'", str);
 
        auth = get_detail (str, ">PASSWORD:Need '");
        if (auth) {
@@ -655,15 +673,15 @@ handle_management_socket (NMOpenvpnPlugin *plugin,
                        /* Request new secrets if we need any */
                        if (message) {
                                if (priv->interactive) {
-                                       if (debug) {
-                                               char *joined = hints ? g_strjoinv (",", (char **) hints) : 
g_strdup ("none");
-                                               g_message ("Requesting new secrets: '%s' (%s)", message, 
joined);
-                                               g_free (joined);
-                                       }
+                                       gs_free char *joined = NULL;
+
+                                       _LOG_d ("Requesting new secrets: '%s', %s%s%s", message,
+                                               NM_PRINT_FMT_QUOTED (hints, "(", (joined = g_strjoinv (",", 
(char **) hints)), ")", "no hints"));
+
                                        nm_vpn_service_plugin_secrets_required ((NMVpnServicePlugin *) 
plugin, message, (const char **) hints);
                                } else {
                                        /* Interactive not allowed, can't ask for more secrets */
-                                       g_warning ("More secrets required but cannot ask interactively");
+                                       _LOG_W ("More secrets required but cannot ask interactively");
                                        *out_failure = NM_VPN_PLUGIN_FAILURE_LOGIN_FAILED;
                                        again = FALSE;
                                }
@@ -671,7 +689,7 @@ handle_management_socket (NMOpenvpnPlugin *plugin,
                        if (hints)
                                g_free (hints);  /* elements are 'const' */
                } else {
-                       g_warning ("Unhandled management socket request '%s'", auth);
+                       _LOG_W ("Unhandled management socket request '%s'", auth);
                        *out_failure = NM_VPN_PLUGIN_FAILURE_CONNECT_FAILED;
                        again = FALSE;
                }
@@ -683,7 +701,7 @@ handle_management_socket (NMOpenvpnPlugin *plugin,
                gboolean fail = TRUE;
 
                if (!strcmp (auth, "Auth")) {
-                       g_warning ("Password verification failed");
+                       _LOG_W ("Password verification failed");
                        if (priv->interactive) {
                                /* Clear existing password in interactive mode, openvpn
                                 * will request a new one after restarting.
@@ -694,9 +712,9 @@ handle_management_socket (NMOpenvpnPlugin *plugin,
                                fail = FALSE;
                        }
                } else if (!strcmp (auth, "Private Key"))
-                       g_warning ("Private key verification failed");
+                       _LOG_W ("Private key verification failed");
                else
-                       g_warning ("Unknown verification failed: %s", auth);
+                       _LOG_W ("Unknown verification failed: %s", auth);
 
                if (fail) {
                        *out_failure = NM_VPN_PLUGIN_FAILURE_LOGIN_FAILED;
@@ -739,7 +757,7 @@ nm_openvpn_connect_timer_cb (gpointer data)
        /* open socket and start listener */
        fd = socket (AF_UNIX, SOCK_STREAM, 0);
        if (fd < 0) {
-               g_warning ("Could not create management socket");
+               _LOG_W ("Could not create management socket");
                nm_vpn_service_plugin_failure (NM_VPN_SERVICE_PLUGIN (plugin), 
NM_VPN_PLUGIN_FAILURE_CONNECT_FAILED);
                goto out;
        }
@@ -753,7 +771,7 @@ nm_openvpn_connect_timer_cb (gpointer data)
 
                priv->connect_timer = 0;
 
-               g_warning ("Could not open management socket");
+               _LOG_W ("Could not open management socket");
                nm_vpn_service_plugin_failure (NM_VPN_SERVICE_PLUGIN (plugin), 
NM_VPN_PLUGIN_FAILURE_CONNECT_FAILED);
        } else {
                io_data->socket_channel = g_io_channel_unix_new (fd);
@@ -1362,7 +1380,7 @@ nm_openvpn_start_openvpn_binary (NMOpenvpnPlugin *plugin,
                add_openvpn_arg (args, "0");
        }
 
-       if (debug) {
+       if (gl.debug) {
                add_openvpn_arg (args, "--verb");
                add_openvpn_arg (args, "10");
        } else {
@@ -1417,7 +1435,7 @@ nm_openvpn_start_openvpn_binary (NMOpenvpnPlugin *plugin,
        /* Up script, called when connection has been established or has been restarted */
        add_openvpn_arg (args, "--up");
        g_object_get (plugin, NM_VPN_SERVICE_PLUGIN_DBUS_SERVICE_NAME, &bus_name, NULL);
-       stmp = g_strdup_printf ("%s%s --bus-name %s %s --", NM_OPENVPN_HELPER_PATH, debug ? " --helper-debug" 
: "",
+       stmp = g_strdup_printf ("%s%s --bus-name %s %s --", NM_OPENVPN_HELPER_PATH, gl.debug ? " 
--helper-debug" : "",
                                bus_name, dev_type_is_tap ? "--tap" : "--tun");
        add_openvpn_arg (args, stmp);
        g_free (stmp);
@@ -1557,17 +1575,16 @@ nm_openvpn_start_openvpn_binary (NMOpenvpnPlugin *plugin,
                        add_openvpn_arg (args, "--chroot");
                        add_openvpn_arg (args, nm_openvpn_chroot);
                } else
-                       g_warning ("Directory '%s' not usable for chroot by '%s', openvpn will not be 
chrooted.",
-                                  nm_openvpn_chroot, nm_openvpn_user);
+                       _LOG_W ("Directory '%s' not usable for chroot by '%s', openvpn will not be chrooted.",
+                               nm_openvpn_chroot, nm_openvpn_user);
        }
 
        g_ptr_array_add (args, NULL);
 
-       if (debug) {
-               char *cmd = g_strjoinv (" ", (char **) args->pdata);
+       {
+               gs_free char *cmd = NULL;
 
-               g_message ("EXEC: '%s'", cmd);
-               g_free (cmd);
+               _LOG_d ("EXEC: '%s'", (cmd = g_strjoinv (" ", (char **) args->pdata)));
        }
 
        if (!g_spawn_async (NULL, (char **) args->pdata, NULL,
@@ -1682,7 +1699,7 @@ _connect_common (NMVpnServicePlugin   *plugin,
        const char *user_name;
 
        if (!real_disconnect (plugin, error)) {
-               g_warning ("Could not clean up previous daemon run: %s", (*error)->message);
+               _LOG_W ("Could not clean up previous daemon run: %s", (*error)->message);
                g_clear_error (error);
        }
 
@@ -1758,8 +1775,8 @@ real_need_secrets (NMVpnServicePlugin *plugin,
        g_return_val_if_fail (NM_IS_VPN_SERVICE_PLUGIN (plugin), FALSE);
        g_return_val_if_fail (NM_IS_CONNECTION (connection), FALSE);
 
-       if (debug) {
-               g_message ("%s: connection -------------------------------------", __func__);
+       if (_LOG_d_enabled ()) {
+               _LOG_d ("connection -------------------------------------");
                nm_connection_dump (connection);
        }
 
@@ -1806,8 +1823,7 @@ real_new_secrets (NMVpnServicePlugin *plugin,
                return FALSE;
        }
 
-       if (debug)
-               g_message ("VPN received new secrets; sending to management interface");
+       _LOG_d ("VPN received new secrets; sending to management interface");
 
        update_io_data_from_vpn_setting (priv->io_data, s_vpn, NULL);
 
@@ -1822,8 +1838,7 @@ real_new_secrets (NMVpnServicePlugin *plugin,
 
        /* Request new secrets if we need any */
        if (message) {
-               if (debug)
-                       g_message ("Requesting new secrets: '%s'", message);
+               _LOG_d ("Requesting new secrets: '%s'", message);
                nm_vpn_service_plugin_secrets_required (plugin, message, (const char **) hints);
        }
        if (hints)
@@ -1904,7 +1919,7 @@ nm_openvpn_plugin_new (const char *bus_name)
        if (plugin) {
                g_signal_connect (G_OBJECT (plugin), "state-changed", G_CALLBACK (plugin_state_changed), 
NULL);
        } else {
-               g_warning ("Failed to initialize a plugin instance: %s", error->message);
+               _LOG_W ("Failed to initialize a plugin instance: %s", error->message);
                g_error_free (error);
        }
 
@@ -1936,7 +1951,7 @@ main (int argc, char *argv[])
 
        GOptionEntry options[] = {
                { "persist", 0, 0, G_OPTION_ARG_NONE, &persist, N_("Don't quit when VPN connection 
terminates"), NULL },
-               { "debug", 0, 0, G_OPTION_ARG_NONE, &debug, N_("Enable verbose debug logging (may expose 
passwords)"), NULL },
+               { "debug", 0, 0, G_OPTION_ARG_NONE, &gl.debug, N_("Enable verbose debug logging (may expose 
passwords)"), NULL },
                { "bus-name", 0, 0, G_OPTION_ARG_STRING, &bus_name, N_("D-Bus name to use for this 
instance"), NULL },
                {NULL}
        };
@@ -1945,6 +1960,9 @@ main (int argc, char *argv[])
        g_type_init ();
 #endif
 
+       if (getenv ("OPENVPN_DEBUG"))
+               gl.debug = TRUE;
+
        /* locale will be set according to environment LC_* variables */
        setlocale (LC_ALL, "");
 
@@ -1964,18 +1982,14 @@ main (int argc, char *argv[])
                                        "OpenVPN capability to NetworkManager."));
 
        if (!g_option_context_parse (opt_ctx, &argc, &argv, &error)) {
-               g_warning ("Error parsing the command line options: %s", error->message);
+               _LOG_W ("Error parsing the command line options: %s", error->message);
                g_option_context_free (opt_ctx);
                g_clear_error (&error);
                exit (1);
        }
        g_option_context_free (opt_ctx);
 
-       if (getenv ("OPENVPN_DEBUG"))
-               debug = TRUE;
-
-       if (debug)
-               g_message ("nm-openvpn-service (version " DIST_VERSION ") starting...");
+       _LOG_d ("nm-openvpn-service (version " DIST_VERSION ") starting...");
 
        if (   !g_file_test ("/sys/class/misc/tun", G_FILE_TEST_EXISTS)
            && (system ("/sbin/modprobe tun") == -1))