[network-manager-fortisslvpn: 28/30] src: use logging macros in service helper and make logging configurable

[Thomas Haller <thaller src gnome org>]

commit 7d71f10607e8d0c449aa4c79d89d1cb827842c0b
Author: Thomas Haller <thaller redhat com>
Date:   Fri Sep 16 17:21:57 2016 +0200

    src: use logging macros in service helper and make logging configurable
    
    Note that the pppd-plugin still uses printf() for logging.
    Seems that pppd redirects stdout and thus these messages
    are actually lost.
    
    This should be fixed somehow. I think the commit still makes
    sense because:
      - logging in this form is not entirely useless. You can
        see them for example when strace'ing the program.
      - if we decide to change printf() to something that actually
        is able to log (syslog()?), having one logging function
        is preferred.

 src/Makefile.am                  |    3 ++
 src/nm-fortisslvpn-pppd-plugin.c |   66 ++++++++++++++++++++++++++-----------
 src/nm-fortisslvpn-service.c     |    3 ++
 3 files changed, 52 insertions(+), 20 deletions(-)
---
diff --git a/src/Makefile.am b/src/Makefile.am
index cdd2fb3..2d5f694 100644
--- a/src/Makefile.am
+++ b/src/Makefile.am
@@ -25,6 +25,9 @@ nodist_libnm_fortisslvpn_pppd_service_dbus_la_SOURCES = \
        nm-fortisslvpn-pppd-service-dbus.c \
        nm-fortisslvpn-pppd-service-dbus.h
 
+libnm_fortisslvpn_pppd_service_dbus_la_SOURCES = \
+       $(shared_sources)
+
 libnm_fortisslvpn_pppd_service_dbus_la_CPPFLAGS = $(filter-out -DGLIB_VERSION_MAX_ALLOWED%,$(AM_CPPFLAGS))
 
 nm-fortisslvpn-pppd-service-dbus.h: $(top_srcdir)/src/nm-fortisslvpn-pppd-service.xml
diff --git a/src/nm-fortisslvpn-pppd-plugin.c b/src/nm-fortisslvpn-pppd-plugin.c
index 9e6fb96..6abbb9d 100644
--- a/src/nm-fortisslvpn-pppd-plugin.c
+++ b/src/nm-fortisslvpn-pppd-plugin.c
@@ -40,14 +40,39 @@
 #include "nm-fortisslvpn-service.h"
 #include "nm-ppp-status.h"
 
+#include "nm-utils/nm-shared-utils.h"
+#include "nm-utils/nm-vpn-plugin-macros.h"
+
 /*****************************************************************************/
 
 static struct {
+       int log_level;
+       const char *log_prefix_token;
        NMDBusFortisslvpnPpp *proxy;
 } gl/*obal*/;
 
 /*****************************************************************************/
 
+/* Note that in the current from, the messages from pppd-plugin are
+ * swallowed by pppd. One way to see them is using strace. */
+
+#define _NMLOG(level, ...) \
+    G_STMT_START { \
+         if (gl.log_level >= (level)) { \
+             g_print ("nm-fortisslvpn[%s] %-7s [helper-%ld] " _NM_UTILS_MACRO_FIRST (__VA_ARGS__) "\n", \
+                      gl.log_prefix_token, \
+                      nm_utils_syslog_to_str (level), \
+                      (long) getpid () \
+                      _NM_UTILS_MACRO_REST (__VA_ARGS__)); \
+         } \
+    } G_STMT_END
+
+#define _LOGI(...) _NMLOG(LOG_NOTICE,  __VA_ARGS__)
+#define _LOGW(...) _NMLOG(LOG_WARNING, __VA_ARGS__)
+#define _LOGE(...) _NMLOG(LOG_ERR, __VA_ARGS__)
+
+/*****************************************************************************/
+
 int plugin_init (void);
 
 char pppd_version[] = VERSION;
@@ -119,10 +144,8 @@ nm_phasechange (void *data, int arg)
                break;
        }
 
-       g_message ("nm-fortisslvpn-ppp-plugin: (%s): status %d / phase '%s'",
-                  __func__,
-                  ppp_status,
-                  ppp_phase);
+       _LOGI ("phasechange: status %d / phase '%s'",
+              ppp_status, ppp_phase);
 
        if (ppp_status != NM_PPP_STATUS_UNKNOWN) {
                nmdbus_fortisslvpn_ppp_call_set_state (gl.proxy,
@@ -207,10 +230,10 @@ nm_ip_up (void *data, int arg)
 
        g_return_if_fail (NMDBUS_IS_FORTISSLVPN_PPP_PROXY (gl.proxy));
 
-       g_message ("nm-fortisslvpn-ppp-plugin: (%s): ip-up event", __func__);
+       _LOGI ("ip-up: event");
 
        if (!opts.ouraddr) {
-               g_warning ("nm-fortisslvpn-ppp-plugin: (%s): didn't receive an internal IP from pppd!", 
__func__);
+               _LOGW ("ip-up: didn't receive an internal IP from pppd!");
                nm_phasechange (NULL, PHASE_DEAD);
                return;
        }
@@ -226,9 +249,8 @@ nm_ip_up (void *data, int arg)
                g_variant_builder_add (&builder, "{sv}",
                                       NM_VPN_PLUGIN_IP4_CONFIG_EXT_GATEWAY,
                                       g_variant_new_uint32 (inet_addr (str)));
-       } else {
-               g_warning ("nm-fortisslvpn-ppp-plugin: (%s): no external gateway!", __func__);
-       }
+       } else
+               _LOGW ("ip-up: no external gateway!");
 
        val = get_ip4_routes (opts.ouraddr);
        if (val)
@@ -281,7 +303,7 @@ nm_ip_up (void *data, int arg)
                               NM_VPN_PLUGIN_IP4_CONFIG_MTU,
                               g_variant_new_uint32 (1400));
 
-       g_message ("nm-fortisslvpn-ppp-plugin: (%s): sending Ip4Config to NetworkManager-fortisslvpn...", 
__func__);
+       _LOGI ("ip-up: sending Ip4Config to NetworkManager-fortisslvpn");
 
        nmdbus_fortisslvpn_ppp_call_set_ip4_config (gl.proxy,
                                                    g_variant_builder_end (&builder),
@@ -294,36 +316,40 @@ nm_exit_notify (void *data, int arg)
 {
        g_return_if_fail (G_IS_DBUS_PROXY (gl.proxy));
 
-       g_message ("nm-fortisslvpn-ppp-plugin: (%s): cleaning up", __func__);
-
+       _LOGI ("exit: cleaning up");
        g_clear_object (&gl.proxy);
 }
 
 int
 plugin_init (void)
 {
-       GError *err = NULL;
+       GError *error = NULL;
        const char *bus_name;
 
        nm_g_type_init ();
 
+       g_return_val_if_fail (!gl.proxy, -1);
+
        bus_name = getenv ("NM_DBUS_SERVICE_FORTISSLVPN");
        if (!bus_name)
                bus_name = NM_DBUS_SERVICE_FORTISSLVPN;
 
-       g_message ("nm-fortisslvpn-ppp-plugin: (%s): initializing", __func__);
+       gl.log_level = _nm_utils_ascii_str_to_int64 (getenv ("NM_VPN_LOG_LEVEL"),
+                                                    10, 0, LOG_DEBUG,
+                                                    LOG_NOTICE);
+       gl.log_prefix_token = getenv ("NM_VPN_LOG_PREFIX_TOKEN") ?: "???";
+
+       _LOGI ("initializing");
 
        gl.proxy = nmdbus_fortisslvpn_ppp_proxy_new_for_bus_sync (G_BUS_TYPE_SYSTEM,
                                                                  G_DBUS_PROXY_FLAGS_DO_NOT_LOAD_PROPERTIES,
                                                                  bus_name,
                                                                  NM_DBUS_PATH_FORTISSLVPN_PPP,
-                                                                 NULL, &err);
+                                                                 NULL, &error);
+
        if (!gl.proxy) {
-               g_warning ("nm-fortisslvpn-pppd-plugin: (%s): couldn't create D-Bus proxy: (%d) %s",
-                          __func__,
-                          err ? err->code : -1,
-                          err && err->message ? err->message : "(unknown)");
-               g_error_free (err);
+               _LOGE ("couldn't create D-Bus proxy: %s", error->message);
+               g_error_free (error);
                return -1;
        }
 
diff --git a/src/nm-fortisslvpn-service.c b/src/nm-fortisslvpn-service.c
index 422302c..5b95b2c 100644
--- a/src/nm-fortisslvpn-service.c
+++ b/src/nm-fortisslvpn-service.c
@@ -793,6 +793,7 @@ main (int argc, char *argv[])
        gs_free char *bus_name_free = NULL;
        const char *bus_name;
        GError *error = NULL;
+       char sbuf[30];
 
        GOptionEntry options[] = {
                { "persist", 0, 0, G_OPTION_ARG_NONE, &persist, N_("Don't quit when VPN connection 
terminates"), NULL },
@@ -856,6 +857,8 @@ main (int argc, char *argv[])
        _LOGD ("nm-fortisslvpn-service (version " DIST_VERSION ") starting...");
        _LOGD ("   uses%s --bus-name \"%s\"", bus_name_free ? "" : " default", bus_name);
 
+       setenv ("NM_VPN_LOG_LEVEL", nm_sprintf_buf (sbuf, "%d", gl.log_level), TRUE);
+       setenv ("NM_VPN_LOG_PREFIX_TOKEN", nm_sprintf_buf (sbuf, "%ld", (long) getpid ()), TRUE);
        setenv ("NM_DBUS_SERVICE_FORTISSLVPN", bus_name, 0);
 
        plugin = nm_fortisslvpn_plugin_new (bus_name);