From patchwork Mon Mar 12 13:43:50 2012 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Johannes Berg X-Patchwork-Id: 146100 Return-Path: X-Original-To: patchwork-incoming@ozlabs.org Delivered-To: patchwork-incoming@ozlabs.org Received: from maxx.maxx.shmoo.com (maxx.shmoo.com [205.134.188.171]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (Client CN "maxx.shmoo.com", Issuer "CA Cert Signing Authority" (not verified)) by ozlabs.org (Postfix) with ESMTPS id E41A7B6F9D for ; Tue, 13 Mar 2012 00:44:06 +1100 (EST) Received: from localhost (localhost [127.0.0.1]) by maxx.maxx.shmoo.com (Postfix) with ESMTP id AAC609C172; Mon, 12 Mar 2012 09:44:03 -0400 (EDT) X-Virus-Scanned: amavisd-new at maxx.shmoo.com Received: from maxx.maxx.shmoo.com ([127.0.0.1]) by localhost (maxx.shmoo.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id ZpnWCDTTW6Zd; Mon, 12 Mar 2012 09:44:03 -0400 (EDT) Received: from maxx.shmoo.com (localhost [127.0.0.1]) by maxx.maxx.shmoo.com (Postfix) with ESMTP id 7000A9C17E; Mon, 12 Mar 2012 09:43:59 -0400 (EDT) X-Original-To: mailman-post+hostap@maxx.shmoo.com Delivered-To: mailman-post+hostap@maxx.shmoo.com Received: from localhost (localhost [127.0.0.1]) by maxx.maxx.shmoo.com (Postfix) with ESMTP id 0456E9C17E for ; Mon, 12 Mar 2012 09:43:58 -0400 (EDT) X-Virus-Scanned: amavisd-new at maxx.shmoo.com Received: from maxx.maxx.shmoo.com ([127.0.0.1]) by localhost (maxx.shmoo.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id knloKHIngOFC for ; Mon, 12 Mar 2012 09:43:52 -0400 (EDT) Received: from sipsolutions.net (he.sipsolutions.net [78.46.109.217]) (using TLSv1 with cipher AES256-SHA (256/256 bits)) (Client did not present a certificate) by maxx.maxx.shmoo.com (Postfix) with ESMTPS id B614F9C172 for ; Mon, 12 Mar 2012 09:43:52 -0400 (EDT) Received: by sipsolutions.net with esmtpsa (TLS1.0:RSA_AES_256_CBC_SHA1:32) (Exim 4.77) (envelope-from ) id 1S75XS-0005UW-Uk for hostap@lists.shmoo.com; Mon, 12 Mar 2012 14:43:51 +0100 Subject: [PATCH] debug: add option to log to tracing From: Johannes Berg To: hostap Date: Mon, 12 Mar 2012 14:43:50 +0100 Message-ID: <1331559830.3496.7.camel@jlt3.sipsolutions.net> Mime-Version: 1.0 X-Mailer: Evolution 2.30.3 X-BeenThere: hostap@lists.shmoo.com X-Mailman-Version: 2.1.9 Precedence: list List-Id: HostAP Project List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Sender: hostap-bounces@lists.shmoo.com Errors-To: hostap-bounces@lists.shmoo.com From: Johannes Berg Add the option (-T) to wpa_supplicant to log all debug messages into the kernel tracing, allowing to aggregate kernel debugging with wpa_supplicant debugging and recording all with trace-cmd. Since tracing is has relatively low overhead and can be filtered afterwards, record all messages regardless of log level. However, it will honour the -K option and not record key material by default. Signed-hostap: Johannes Berg --- src/utils/wpa_debug.c | 130 +++++++++++++++++++++++++++++++++++++ src/utils/wpa_debug.h | 13 ++++ wpa_supplicant/Makefile | 4 + wpa_supplicant/defconfig | 6 ++ wpa_supplicant/main.c | 11 +++- wpa_supplicant/wpa_supplicant.c | 9 +++ wpa_supplicant/wpa_supplicant_i.h | 5 ++ 7 files changed, 177 insertions(+), 1 deletions(-) diff --git a/src/utils/wpa_debug.c b/src/utils/wpa_debug.c index 858a97c..2777121 100644 --- a/src/utils/wpa_debug.c +++ b/src/utils/wpa_debug.c @@ -16,6 +16,18 @@ static int wpa_debug_syslog = 0; #endif /* CONFIG_DEBUG_SYSLOG */ +#ifdef CONFIG_DEBUG_LINUX_TRACING +#include +#include +#include +#include +#include + +static FILE *wpa_debug_tracing_file = NULL; + +#define WPAS_TRACE_PFX "wpas <%d>: " +#endif /* CONFIG_DEBUG_LINUX_TRACING */ + int wpa_debug_level = MSG_INFO; int wpa_debug_show_keys = 0; @@ -106,6 +118,72 @@ static int syslog_priority(int level) } #endif /* CONFIG_DEBUG_SYSLOG */ +#ifdef CONFIG_DEBUG_LINUX_TRACING +int wpa_debug_open_linux_tracing(void) +{ + int mounts, trace_fd; + char buf[4096] = {}; + ssize_t buflen; + char *line, *tmp1, *path = NULL; + + mounts = open("/proc/mounts", O_RDONLY); + if (mounts < 0) { + printf("no /proc/mounts\n"); + return -1; + } + + buflen = read(mounts, buf, sizeof(buf) - 1); + close(mounts); + if (buflen < 0) { + printf("failed to read /proc/mounts\n"); + return -1; + } + + line = strtok_r(buf, "\n", &tmp1); + if (line) do { + char *tmp2, *tmp_path, *fstype; + + /* " ..." */ + strtok_r(line, " ", &tmp2); + tmp_path = strtok_r(NULL, " ", &tmp2); + fstype = strtok_r(NULL, " ", &tmp2); + if (strcmp(fstype, "debugfs") == 0) { + path = tmp_path; + break; + } + } while ((line = strtok_r(NULL, "\n", &tmp1))); + + if (path == NULL) { + printf("debugfs mountpoint not found\n"); + return -1; + } + + snprintf(buf, sizeof(buf) - 1, "%s/tracing/trace_marker", path); + + trace_fd = open(buf, O_WRONLY); + if (trace_fd < 0) { + printf("failed to open trace_marker file\n"); + return -1; + } + wpa_debug_tracing_file = fdopen(trace_fd, "w"); + if (wpa_debug_tracing_file == NULL) { + close(trace_fd); + printf("failed to fdopen()\n"); + return -1; + } + + return 0; +} + +void wpa_debug_close_linux_tracing(void) +{ + if (wpa_debug_tracing_file == NULL) + return; + fclose(wpa_debug_tracing_file); + wpa_debug_tracing_file = NULL; +} +#endif /* CONFIG_DEBUG_LINUX_TRACING */ + /** * wpa_printf - conditional printf @@ -151,6 +229,16 @@ void wpa_printf(int level, const char *fmt, ...) #endif /* CONFIG_ANDROID_LOG */ } va_end(ap); +#ifdef CONFIG_DEBUG_LINUX_TRACING + if (wpa_debug_tracing_file != NULL) { + va_start(ap, fmt); + fprintf(wpa_debug_tracing_file, WPAS_TRACE_PFX, level); + vfprintf(wpa_debug_tracing_file, fmt, ap); + fprintf(wpa_debug_tracing_file, "\n"); + fflush(wpa_debug_tracing_file); + va_end(ap); + } +#endif /* CONFIG_DEBUG_LINUX_TRACING */ } @@ -158,6 +246,25 @@ static void _wpa_hexdump(int level, const char *title, const u8 *buf, size_t len, int show) { size_t i; + +#ifdef CONFIG_DEBUG_LINUX_TRACING + if (wpa_debug_tracing_file != NULL) { + fprintf(wpa_debug_tracing_file, + WPAS_TRACE_PFX "%s - hexdump(len=%lu):", + level, title, (unsigned long) len); + if (buf == NULL) { + fprintf(wpa_debug_tracing_file, " [NULL]\n"); + } else if (!show) { + fprintf(wpa_debug_tracing_file, " [REMOVED]\n"); + } else { + for (i = 0; i < len; i++) + fprintf(wpa_debug_tracing_file, + " %02x", buf[i]); + } + fflush(wpa_debug_tracing_file); + } +#endif /* CONFIG_DEBUG_LINUX_TRACING */ + if (level < wpa_debug_level) return; #ifdef CONFIG_ANDROID_LOG @@ -281,6 +388,29 @@ static void _wpa_hexdump_ascii(int level, const char *title, const u8 *buf, const u8 *pos = buf; const size_t line_len = 16; +#ifdef CONFIG_DEBUG_LINUX_TRACING + if (wpa_debug_tracing_file != NULL) { + size_t orig_len = len; + + fprintf(wpa_debug_tracing_file, + WPAS_TRACE_PFX "%s - hexdump_ascii(len=%lu):", + level, title, (unsigned long) len); + if (buf == NULL) { + fprintf(wpa_debug_tracing_file, " [NULL]\n"); + } else if (!show) { + fprintf(wpa_debug_tracing_file, " [REMOVED]\n"); + } else { + /* can do ascii processing in userspace */ + for (i = 0; i < len; i++) + fprintf(wpa_debug_tracing_file, + " %02x", buf[i]); + } + fflush(wpa_debug_tracing_file); + + len = orig_len; + } +#endif /* CONFIG_DEBUG_LINUX_TRACING */ + if (level < wpa_debug_level) return; #ifdef CONFIG_ANDROID_LOG diff --git a/src/utils/wpa_debug.h b/src/utils/wpa_debug.h index c79907a..2aac1c5 100644 --- a/src/utils/wpa_debug.h +++ b/src/utils/wpa_debug.h @@ -255,6 +255,19 @@ static inline void wpa_debug_close_syslog(void) #endif /* CONFIG_DEBUG_SYSLOG */ +#ifdef CONFIG_DEBUG_LINUX_TRACING +int wpa_debug_open_linux_tracing(void); +void wpa_debug_close_linux_tracing(void); +#else +static inline int wpa_debug_open_linux_tracing(void) +{ + return 0; +} +static inline void wpa_debug_close_linux_tracing(void) +{ +} +#endif /* CONFIG_DEBUG_LINUX_TRACING */ + #ifdef EAPOL_TEST #define WPA_ASSERT(a) \ diff --git a/wpa_supplicant/Makefile b/wpa_supplicant/Makefile index a976098..b3a9d55 100644 --- a/wpa_supplicant/Makefile +++ b/wpa_supplicant/Makefile @@ -1273,6 +1273,10 @@ CFLAGS += -DLOG_HOSTAPD="$(CONFIG_DEBUG_SYSLOG_FACILITY)" endif endif +ifdef CONFIG_DEBUG_LINUX_TRACING +CFLAGS += -DCONFIG_DEBUG_LINUX_TRACING +endif + ifdef CONFIG_DEBUG_FILE CFLAGS += -DCONFIG_DEBUG_FILE endif diff --git a/wpa_supplicant/defconfig b/wpa_supplicant/defconfig index 480bc64..2668e6d 100644 --- a/wpa_supplicant/defconfig +++ b/wpa_supplicant/defconfig @@ -413,6 +413,12 @@ CONFIG_PEERKEY=y # Set syslog facility for debug messages #CONFIG_DEBUG_SYSLOG_FACILITY=LOG_DAEMON +# Add support for sending all debug messages (regardless of debug verbosity) +# to the Linux kernel tracing facility. This helps debug the entire stack by +# making it easy to record everything happening from the driver up into the +# same file, e.g. using trace-cmd. +#CONFIG_DEBUG_LINUX_TRACING=y + # Enable privilege separation (see README 'Privilege separation' for details) #CONFIG_PRIVSEP=y diff --git a/wpa_supplicant/main.c b/wpa_supplicant/main.c index c124ca2..5ccdf3c 100644 --- a/wpa_supplicant/main.c +++ b/wpa_supplicant/main.c @@ -61,6 +61,10 @@ static void usage(void) #ifdef CONFIG_DEBUG_SYSLOG printf(" -s = log output to syslog instead of stdout\n"); #endif /* CONFIG_DEBUG_SYSLOG */ +#ifdef CONFIG_DEBUG_LINUX_TRACING + printf(" -T = record to Linux tracing in addition to logging\n"); + printf(" (records all messages regardless of debug verbosity)\n"); +#endif /* CONFIG_DEBUG_LINUX_TRACING */ printf(" -t = include timestamp in debug messages\n" " -h = show this help text\n" " -L = show license (BSD)\n" @@ -139,7 +143,7 @@ int main(int argc, char *argv[]) wpa_supplicant_fd_workaround(); for (;;) { - c = getopt(argc, argv, "b:Bc:C:D:de:f:g:hi:KLNo:O:p:P:qstuvW"); + c = getopt(argc, argv, "b:Bc:C:D:de:f:g:hi:KLNo:O:p:P:qsTtuvW"); if (c < 0) break; switch (c) { @@ -214,6 +218,11 @@ int main(int argc, char *argv[]) params.wpa_debug_syslog++; break; #endif /* CONFIG_DEBUG_SYSLOG */ +#ifdef CONFIG_DEBUG_LINUX_TRACING + case 'T': + params.wpa_debug_tracing++; + break; +#endif /* CONFIG_DEBUG_LINUX_TRACING */ case 't': params.wpa_debug_timestamp++; break; diff --git a/wpa_supplicant/wpa_supplicant.c b/wpa_supplicant/wpa_supplicant.c index 36074d5..87de57d 100644 --- a/wpa_supplicant/wpa_supplicant.c +++ b/wpa_supplicant/wpa_supplicant.c @@ -2874,6 +2874,14 @@ struct wpa_global * wpa_supplicant_init(struct wpa_params *params) wpa_debug_open_file(params->wpa_debug_file_path); if (params->wpa_debug_syslog) wpa_debug_open_syslog(); + if (params->wpa_debug_tracing) { + ret = wpa_debug_open_linux_tracing(); + if (ret) { + wpa_printf(MSG_ERROR, + "Failed to enable trace logging\n"); + return NULL; + } + } ret = eap_register_methods(); if (ret) { @@ -3036,6 +3044,7 @@ void wpa_supplicant_deinit(struct wpa_global *global) os_free(global); wpa_debug_close_syslog(); wpa_debug_close_file(); + wpa_debug_close_linux_tracing(); } diff --git a/wpa_supplicant/wpa_supplicant_i.h b/wpa_supplicant/wpa_supplicant_i.h index 0ba1935..e2e0aed 100644 --- a/wpa_supplicant/wpa_supplicant_i.h +++ b/wpa_supplicant/wpa_supplicant_i.h @@ -161,6 +161,11 @@ struct wpa_params { int wpa_debug_syslog; /** + * wpa_debug_tracing - Enable log output through Linux tracing + */ + int wpa_debug_tracing; + + /** * override_driver - Optional driver parameter override * * This parameter can be used to override the driver parameter in