logging,vpn: merge branch 'th/vpn-plugin-debug-bgo766816'

https://bugzilla.gnome.org/show_bug.cgi?id=766816

4 files changed, 129 insertions, 8 deletions

diff --git a/man/NetworkManager.conf.xml b/man/NetworkManager.conf.xml
index 036f41d003..fd6d7cef59 100644
--- a/man/NetworkManager.conf.xml
+++ b/man/NetworkManager.conf.xml
@@ -460,7 +460,7 @@ unmanaged-devices=mac:00:22:68:1c:59:b1;mac:00:1E:65:30:D1:C4;interface-name:eth
           WIFI_SCAN, IP4, IP6, AUTOIP4, DNS, VPN, SHARING, SUPPLICANT,
           AGENTS, SETTINGS, SUSPEND, CORE, DEVICE, OLPC, WIMAX,
           INFINIBAND, FIREWALL, ADSL, BOND, VLAN, BRIDGE, DBUS_PROPS,
-          TEAM, CONCHECK, DCB, DISPATCH, AUDIT, SYSTEMD.</para>
+          TEAM, CONCHECK, DCB, DISPATCH, AUDIT, SYSTEMD, VPN_PLUGIN.</para>
           <para>In addition, these special domains can be used: NONE,
           ALL, DEFAULT, DHCP, IP.</para>
           <para>You can specify per-domain log level overrides by
@@ -507,6 +507,7 @@ unmanaged-devices=mac:00:22:68:1c:59:b1;mac:00:1E:65:30:D1:C4;interface-name:eth
           <member>DISPATCH    : Dispatcher scripts</member>
           <member>AUDIT       : Audit records</member>
           <member>SYSTEMD     : Messages from internal libsystemd</member>
+          <member>VPN_PLUGIN  : logging messages from VPN plugins</member>
           <member> </member>
           <member>NONE        : when given by itself logging is disabled</member>
           <member>ALL         : all log domains</member>
@@ -517,6 +518,12 @@ unmanaged-devices=mac:00:22:68:1c:59:b1;mac:00:1E:65:30:D1:C4;interface-name:eth
           <member>HW          : deprecated alias for "PLATFORM"</member>
           </simplelist>
           </para>
+          <para>
+          In general, the logfile should not contain passwords or private data. However,
+          you are always advised to check the file before posting it online or attaching
+          to a bug report. <literal>VPN_PLUGIN</literal> is special in that it might
+          reveal private information from the VPN plugins and thus this level is excluded
+          from <literal>ALL</literal></para>
         </varlistentry>
         <varlistentry>
           <term><varname>backend</varname></term>
diff --git a/src/nm-logging.c b/src/nm-logging.c
index a2581add24..4d9b3fbd45 100644
--- a/src/nm-logging.c
+++ b/src/nm-logging.c
@@ -93,7 +93,16 @@ typedef struct {
 typedef struct {
 	const char *name;
 	const char *level_str;
+
+	/* nm-logging uses syslog internally. Note that the three most-verbose syslog levels
+	 * are LOG_DEBUG, LOG_INFO and LOG_NOTICE. Journal already highlights LOG_NOTICE
+	 * as special.
+	 *
+	 * On the other hand, we have three levels LOGL_TRACE, LOGL_DEBUG and LOGL_INFO,
+	 * which are regular messages not to be highlighted. For that reason, we must map
+	 * LOGL_TRACE and LOGL_DEBUG both to syslog level LOG_DEBUG. */
 	int syslog_level;
+
 	GLogLevelFlags g_log_level;
 	LogFormatFlags log_format_level;
 } LogLevelDesc;
@@ -108,6 +117,7 @@ NMLogDomain _nm_logging_enabled_state[_LOGL_N_REAL] = {
 static struct {
 	NMLogLevel log_level;
 	LogFormatFlags log_format_flags;
+	bool uses_syslog:1;
 	enum {
 		LOG_BACKEND_GLIB,
 		LOG_BACKEND_SYSLOG,
@@ -116,7 +126,7 @@ static struct {
 	char *logging_domains_to_string;
 	const LogLevelDesc level_desc[_LOGL_N];
 
-#define _DOMAIN_DESC_LEN 37
+#define _DOMAIN_DESC_LEN 38
 	/* Would be nice to use C99 flexible array member here,
 	 * but that feature doesn't seem well supported. */
 	const LogDesc domain_desc[_DOMAIN_DESC_LEN];
@@ -127,7 +137,7 @@ static struct {
 	.log_format_flags = _LOG_FORMAT_FLAG_DEFAULT,
 	.level_desc = {
 		[LOGL_TRACE] = { "TRACE", "<trace>", LOG_DEBUG,   G_LOG_LEVEL_DEBUG,   _LOG_FORMAT_FLAG_LEVEL_DEBUG },
-		[LOGL_DEBUG] = { "DEBUG", "<debug>", LOG_INFO,    G_LOG_LEVEL_DEBUG,   _LOG_FORMAT_FLAG_LEVEL_DEBUG },
+		[LOGL_DEBUG] = { "DEBUG", "<debug>", LOG_DEBUG,   G_LOG_LEVEL_DEBUG,   _LOG_FORMAT_FLAG_LEVEL_DEBUG },
 		[LOGL_INFO]  = { "INFO",  "<info>",  LOG_INFO,    G_LOG_LEVEL_INFO,    _LOG_FORMAT_FLAG_LEVEL_INFO },
 		[LOGL_WARN]  = { "WARN",  "<warn>",  LOG_WARNING, G_LOG_LEVEL_MESSAGE, _LOG_FORMAT_FLAG_LEVEL_INFO },
 		[LOGL_ERR]   = { "ERR",   "<error>", LOG_ERR,     G_LOG_LEVEL_MESSAGE, _LOG_FORMAT_FLAG_LEVEL_ERROR },
@@ -171,6 +181,7 @@ static struct {
 		{ LOGD_DISPATCH,  "DISPATCH" },
 		{ LOGD_AUDIT,     "AUDIT" },
 		{ LOGD_SYSTEMD,   "SYSTEMD" },
+		{ LOGD_VPN_PLUGIN,"VPN_PLUGIN" },
 		{ 0, NULL }
 		/* keep _DOMAIN_DESC_LEN in sync */
 	},
@@ -445,6 +456,27 @@ nm_logging_all_domains_to_string (void)
 	return str->str;
 }
 
+/**
+ * nm_logging_get_level:
+ * @domain: find the lowest enabled logging level for the
+ *   given domain. If this is a set of multiple
+ *   domains, the most verbose level will be returned.
+ *
+ * Returns: the lowest (most verbose) logging level for the
+ *   give @domain, or %_LOGL_OFF if it is disabled.
+ **/
+NMLogLevel
+nm_logging_get_level (NMLogDomain domain)
+{
+	NMLogLevel sl = _LOGL_OFF;
+
+	G_STATIC_ASSERT (LOGL_TRACE == 0);
+	while (   sl > LOGL_TRACE
+	       && nm_logging_enabled (sl - 1, domain))
+		sl--;
+	return sl;
+}
+
 #if SYSTEMD_JOURNAL
 __attribute__((__format__ (__printf__, 4, 5)))
 static void
@@ -716,6 +748,12 @@ nm_log_handler (const gchar *log_domain,
 	}
 }
 
+gboolean
+nm_logging_syslog_enabled (void)
+{
+	return global.uses_syslog;
+}
+
 void
 nm_logging_syslog_openlog (const char *logging_backend)
 {
@@ -735,6 +773,7 @@ nm_logging_syslog_openlog (const char *logging_backend)
 #if SYSTEMD_JOURNAL
 	} else if (strcmp (logging_backend, "syslog") != 0) {
 		global.log_backend = LOG_BACKEND_JOURNAL;
+		global.uses_syslog = TRUE;
 
 		/* ensure we read a monotonic timestamp. Reading the timestamp the first
 		 * time causes a logging message. We don't want to do that during _nm_log_impl. */
@@ -742,6 +781,7 @@ nm_logging_syslog_openlog (const char *logging_backend)
 #endif
 	} else {
 		global.log_backend = LOG_BACKEND_SYSLOG;
+		global.uses_syslog = TRUE;
 		openlog (G_LOG_DOMAIN, LOG_PID, LOG_DAEMON);
 	}
 
diff --git a/src/nm-logging.h b/src/nm-logging.h
index 1cb5a5a5d9..f49f6ec67b 100644
--- a/src/nm-logging.h
+++ b/src/nm-logging.h
@@ -65,12 +65,16 @@ typedef enum  { /*< skip >*/
 	LOGD_DISPATCH   = (1LL << 33),
 	LOGD_AUDIT      = (1LL << 34),
 	LOGD_SYSTEMD    = (1LL << 35),
+	LOGD_VPN_PLUGIN = (1LL << 36),
 
 	__LOGD_MAX,
-	LOGD_ALL       = ((__LOGD_MAX - 1LL) << 1) - 1LL,
+	LOGD_ALL       = (((__LOGD_MAX - 1LL) << 1) - 1LL) & ~(
+	                                                       LOGD_VPN_PLUGIN | /*not even part of ALL, because it might expose sensitive information. */
+	                                                       0),
 	LOGD_DEFAULT   = LOGD_ALL & ~(
 	                              LOGD_DBUS_PROPS |
 	                              LOGD_WIFI_SCAN |
+	                              LOGD_VPN_PLUGIN |
 	                              0),
 
 	/* aliases: */
@@ -168,6 +172,8 @@ nm_logging_enabled (NMLogLevel level, NMLogDomain domain)
 	       && !!(_nm_logging_enabled_state[level] & domain);
 }
 
+NMLogLevel nm_logging_get_level (NMLogDomain domain);
+
 const char *nm_logging_all_levels_to_string (void);
 const char *nm_logging_all_domains_to_string (void);
 
@@ -176,6 +182,7 @@ gboolean nm_logging_setup (const char  *level,
                            char       **bad_domains,
                            GError     **error);
 void     nm_logging_syslog_openlog (const char *logging_backend);
+gboolean nm_logging_syslog_enabled (void);
 
 /*****************************************************************************/
 
diff --git a/src/vpn-manager/nm-vpn-connection.c b/src/vpn-manager/nm-vpn-connection.c
index c235748741..410256027f 100644
--- a/src/vpn-manager/nm-vpn-connection.c
+++ b/src/vpn-manager/nm-vpn-connection.c
@@ -27,6 +27,8 @@
 #include <arpa/inet.h>
 #include <errno.h>
 #include <stdlib.h>
+#include <unistd.h>
+#include <syslog.h>
 
 #include "nm-vpn-connection.h"
 #include "nm-ip4-config.h"
@@ -1922,6 +1924,41 @@ _daemon_exec_timeout (gpointer data)
 	return G_SOURCE_REMOVE;
 }
 
+static int
+_get_log_level (void)
+{
+	NMLogLevel level;
+
+	/* curiously enough, nm-logging also uses syslog. But it
+	 * maps NMLogLevel differently to the syslog levels then we
+	 * do here.
+	 *
+	 * The reason is, that LOG_NOTICE is already something worth
+	 * highlighting in the journal, but we have 3 levels that are
+	 * lower then LOG_NOTICE (LOGL_TRACE, LOGL_DEBUG, LOGL_INFO),
+	 * On the other hand, syslog only defines LOG_DEBUG and LOG_INFO.
+	 * Thus, we must map them differently.
+	 *
+	 * Inside the VPN plugin, you might want to treat LOG_NOTICE as
+	 * as low severity, not worthy to be highlighted (like NM does). */
+
+	level = nm_logging_get_level (LOGD_VPN_PLUGIN);
+	if (level != _LOGL_OFF) {
+		if (level <= LOGL_TRACE)
+			return LOG_DEBUG;
+		if (level <= LOGL_DEBUG)
+			return LOG_INFO;
+		if (level <= LOGL_INFO)
+			return LOG_NOTICE;
+		if (level <= LOGL_WARN)
+			return LOG_WARNING;
+		if (level <= LOGL_ERR)
+			return LOG_ERR;
+	}
+
+	return LOG_EMERG;
+}
+
 static gboolean
 nm_vpn_service_daemon_exec (NMVpnConnection *self, GError **error)
 {
@@ -1930,20 +1967,50 @@ nm_vpn_service_daemon_exec (NMVpnConnection *self, GError **error)
 	char *vpn_argv[4];
 	gboolean success = FALSE;
 	GError *spawn_error = NULL;
-	int i = 0;
+	guint i, j, n_environ;
+	gs_free char **envp = NULL;
+	char env_log_level[NM_STRLEN ("NM_VPN_LOG_LEVEL=") + 100];
+	char env_log_syslog[NM_STRLEN ("NM_VPN_LOG_SYSLOG=") + 10];
+	const int N_ENVIRON_EXTRA = 3;
+	char **p_environ;
 
 	g_return_val_if_fail (NM_IS_VPN_CONNECTION (self), FALSE);
+
 	priv = NM_VPN_CONNECTION_GET_PRIVATE (self);
 
+	i = 0;
 	vpn_argv[i++] = (char *) nm_vpn_plugin_info_get_program (priv->plugin_info);
+	g_return_val_if_fail (vpn_argv[0], FALSE);
 	if (nm_vpn_plugin_info_supports_multiple (priv->plugin_info)) {
 		vpn_argv[i++] = "--bus-name";
 		vpn_argv[i++] = priv->bus_name;
 	}
-	vpn_argv[i] = NULL;
-	g_assert (vpn_argv[0]);
+	vpn_argv[i++] = NULL;
+
+	/* we include <unistd.h> and "config.h" defines _GNU_SOURCE for us. So, we have @environ. */
+	p_environ = environ;
+	n_environ = p_environ ? g_strv_length (p_environ) : 0;
+	envp = g_new (char *, n_environ + N_ENVIRON_EXTRA);
+	for (i = 0, j = 0; j < n_environ; j++) {
+		if (   g_str_has_prefix (p_environ[j], "NM_VPN_LOG_LEVEL=")
+		    || g_str_has_prefix (p_environ[j], "NM_VPN_LOG_SYSLOG="))
+			continue;
+		envp[i++] = p_environ[j];
+	}
+
+	/* NM_VPN_LOG_LEVEL: the syslog logging level for the plugin. */
+	envp[i++] = nm_sprintf_buf (env_log_level,  "NM_VPN_LOG_LEVEL=%d", _get_log_level ());
+
+	/* NM_VPN_LOG_SYSLOG: whether to log to stdout or syslog. If NetworkManager itself runs in
+	 * foreground, we also want the plugin to log to stdout.
+	 * If the plugin runs in background, the plugin should prefer logging to syslog. Otherwise
+	 * logging messages will be lost (unless using journald, in which case it wouldn't matter). */
+	envp[i++] = nm_sprintf_buf (env_log_syslog, "NM_VPN_LOG_SYSLOG=%c", nm_logging_syslog_enabled () ? '1' : '0');
+
+	envp[i++] = NULL;
+	nm_assert (i <= n_environ + N_ENVIRON_EXTRA);
 
-	success = g_spawn_async (NULL, vpn_argv, NULL, 0, nm_utils_setpgid, NULL, &pid, &spawn_error);
+	success = g_spawn_async (NULL, vpn_argv, envp, 0, nm_utils_setpgid, NULL, &pid, &spawn_error);
 
 	if (success) {
 		_LOGI ("Started the VPN service, PID %ld", (long int) pid);