From patchwork Mon Dec 5 11:24:44 2016 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Robert Bragg X-Patchwork-Id: 9460859 Return-Path: Received: from mail.wl.linuxfoundation.org (pdx-wl-mail.web.codeaurora.org [172.30.200.125]) by pdx-korg-patchwork.web.codeaurora.org (Postfix) with ESMTP id 673CF60236 for ; Mon, 5 Dec 2016 11:25:08 +0000 (UTC) Received: from mail.wl.linuxfoundation.org (localhost [127.0.0.1]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id 5769624B44 for ; Mon, 5 Dec 2016 11:25:08 +0000 (UTC) Received: by mail.wl.linuxfoundation.org (Postfix, from userid 486) id 4C02626419; Mon, 5 Dec 2016 11:25:08 +0000 (UTC) X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on pdx-wl-mail.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-4.1 required=2.0 tests=BAYES_00,DKIM_SIGNED, RCVD_IN_DNSWL_MED, T_DKIM_INVALID autolearn=unavailable version=3.3.1 Received: from gabe.freedesktop.org (gabe.freedesktop.org [131.252.210.177]) (using TLSv1.2 with cipher DHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by mail.wl.linuxfoundation.org (Postfix) with ESMTPS id 9831324B44 for ; Mon, 5 Dec 2016 11:25:07 +0000 (UTC) Received: from gabe.freedesktop.org (localhost [127.0.0.1]) by gabe.freedesktop.org (Postfix) with ESMTP id 0FEDA6E201; Mon, 5 Dec 2016 11:24:58 +0000 (UTC) X-Original-To: intel-gfx@lists.freedesktop.org Delivered-To: intel-gfx@lists.freedesktop.org Received: from mail-wj0-x243.google.com (mail-wj0-x243.google.com [IPv6:2a00:1450:400c:c01::243]) by gabe.freedesktop.org (Postfix) with ESMTPS id E996C6E1F9; Mon, 5 Dec 2016 11:24:55 +0000 (UTC) Received: by mail-wj0-x243.google.com with SMTP id he10so24529144wjc.2; Mon, 05 Dec 2016 03:24:55 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=sender:from:to:cc:subject:date:message-id; bh=uu/RS7FOKq2e6Vd3KmKdHSndgKXGYkWzldp+vBqj4zM=; b=bWR6sxwM3AUhQtBWgLwCQ6S6JS4RGf0M26YDchXXh6dcZaN2nFPsRtKbEeg1iHjn/1 gCSHeRie3M3bJqCgl1+XU8BqNUKOJJmbPvNZQaAsbyss+2CkHT1V5MY6SBxrc9f4EpAu +TKCMSv7UlgfcUOw0pwMRb9/Ko9rc3xZo86My5d722HZeUiGRRTSCAMcQQfu0Nc1vkaN GzwCHZIbSNBamLGPbpYw/y3ABpVvK475AX5UgzMFCgTddElrAN47JIDrl6FHewr2PJqp BLhyrAmzq5onuzVyC65zc6zrkwAbjiNq8AnDzqrGLngcq/DtVGSBfmr811wj0GnuICGj V88g== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:sender:from:to:cc:subject:date:message-id; bh=uu/RS7FOKq2e6Vd3KmKdHSndgKXGYkWzldp+vBqj4zM=; b=lxiJ2j4HTdHlxrYOjp8O4058Txe9FFwQWLRZrNMt+k5cR3ns3hCpqmeJZrmYXG6FLQ creKCJI3ow6a23ZkTwc4KZW4bLMWRpxQ/w/hxM0dtlS1elA4o0E/lN9igDmFGnNixd9D 61NoM438LXMeDBDmWaqLUstg58Pm34bRUS1/J0/6c99Lv0q6q2Ld47REYxaRnkrRHUw5 Sl+0uv9zB0U7Hi0hS/tWvrzA/cGHc16T9Q4+8kHk59UTnYgAM22xZiYMbRi0WuKovZ/n bfWLNV8qoacyvah3Fp4tUFXfMjnVTHDjQkJjzS6+U9nnYDBJcfxaUHEFnWm3t1k/jg9z ya1g== X-Gm-Message-State: AKaTC00eyfSakf3cY8FG3bEPgvHY8B9oB1aRvhVuuJcdMsYsbo5a00qXCuc2tEQXeZnyEw== X-Received: by 10.194.77.83 with SMTP id q19mr48993621wjw.186.1480937094256; Mon, 05 Dec 2016 03:24:54 -0800 (PST) Received: from sixbynine.org (host-78-151-18-29.as13285.net. [78.151.18.29]) by smtp.gmail.com with ESMTPSA id i10sm19916535wjd.15.2016.12.05.03.24.53 (version=TLS1_2 cipher=ECDHE-RSA-CHACHA20-POLY1305 bits=256/256); Mon, 05 Dec 2016 03:24:53 -0800 (PST) From: Robert Bragg To: dri-devel@lists.freedesktop.org Date: Mon, 5 Dec 2016 11:24:44 +0000 Message-Id: <20161205112444.21015-1-robert@sixbynine.org> X-Mailer: git-send-email 2.10.2 Cc: Daniel Vetter , intel-gfx@lists.freedesktop.org Subject: [Intel-gfx] [RFC] drm: Enable dynamic debug for DRM_[DEV]_DEBUG* X-BeenThere: intel-gfx@lists.freedesktop.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: Intel graphics driver community testing & development List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , MIME-Version: 1.0 Errors-To: intel-gfx-bounces@lists.freedesktop.org Sender: "Intel-gfx" X-Virus-Scanned: ClamAV using ClamSMTP Forgot to send to dri-devel when I first sent this out... The few times I've looked at using DRM_DEBUG messages, I haven't found them very helpful considering how noisy some of the categories are. More than once now I've preferred to go in and modify individual files to affect what messages I see and re-build. After recently converting some of the i915_perf.c messages to use DRM_DEBUG, I thought I'd see if DRM_DEBUG could be updated to have a bit more fine grained control than the current category flags. A few things to note with this first iteration: - I haven't looked to see what affect the change has on linked object sizes. - It seems like it could be nice if dynamic debug could effectively make the drm_debug parameter redundant but dynamic debug doesn't give us a way to categorise messages so maybe we'd want to consider including categories in messages something like: "[drm][kms] No FB found" This way all kms messages could be enabled via: echo "format [kms] +p" > dynamic_debug/control Note with this simple scheme categories would no longer be mutually exclusive which could be a nice bonus. Since it would involve changing the output format, I wonder how concerned others might be about breaking some userspace (maybe CI test runners) that for some reason grep for specific messages? --- >8 --- (git am --scissors) Dynamic debug messages (ref: Documentation/dynamic-debug-howto.txt) allow fine grained control over which debug messages are enabled with runtime control through /sysfs/kernel/debug/dynamic_debug/control This provides more control than the current drm.drm_debug parameter which for some use cases is impractical to use given how chatty some drm debug categories are. For example all debug messages in i915_drm.c can be enabled with: echo "file i915_perf.c +p" > dynamic_debug/control This aims to maintain compatibility with controlling debug messages using the drm_debug parameter. The new dynamic debug macros are called by default but conditionally calling [dev_]printk if the category flag is set (side stepping the dynamic debug condition in that case) This removes the drm_[dev_]printk wrappers considering that the dynamic debug macros are only useful if they can track the __FILE__, __func__ and __LINE__ where they are called. The wrapper didn't seem necessary in the DRM_UT_NONE case with no category flag. The output format should be compatible, unless the _DEV macros are passed a NULL dev pointer considering how the core.c dev_printk implementation adds "(NULL device *)" to the message in that case while the drm wrapper would fallback to a plain printk in this case. Previously some of non-dev drm debug macros were defined in terms of passing NULL to a dev version but that's avoided now due to this difference. Signed-off-by: Robert Bragg Cc: dri-devel@lists.freedesktop.org Cc: Daniel Vetter Cc: Chris Wilson --- drivers/gpu/drm/drm_drv.c | 47 ------------- include/drm/drmP.h | 168 +++++++++++++++++++++++++++++----------------- 2 files changed, 108 insertions(+), 107 deletions(-) diff --git a/drivers/gpu/drm/drm_drv.c b/drivers/gpu/drm/drm_drv.c index f74b7d0..25d00aa 100644 --- a/drivers/gpu/drm/drm_drv.c +++ b/drivers/gpu/drm/drm_drv.c @@ -65,53 +65,6 @@ static struct idr drm_minors_idr; static struct dentry *drm_debugfs_root; -#define DRM_PRINTK_FMT "[" DRM_NAME ":%s]%s %pV" - -void drm_dev_printk(const struct device *dev, const char *level, - unsigned int category, const char *function_name, - const char *prefix, const char *format, ...) -{ - struct va_format vaf; - va_list args; - - if (category != DRM_UT_NONE && !(drm_debug & category)) - return; - - va_start(args, format); - vaf.fmt = format; - vaf.va = &args; - - if (dev) - dev_printk(level, dev, DRM_PRINTK_FMT, function_name, prefix, - &vaf); - else - printk("%s" DRM_PRINTK_FMT, level, function_name, prefix, &vaf); - - va_end(args); -} -EXPORT_SYMBOL(drm_dev_printk); - -void drm_printk(const char *level, unsigned int category, - const char *format, ...) -{ - struct va_format vaf; - va_list args; - - if (category != DRM_UT_NONE && !(drm_debug & category)) - return; - - va_start(args, format); - vaf.fmt = format; - vaf.va = &args; - - printk("%s" "[" DRM_NAME ":%ps]%s %pV", - level, __builtin_return_address(0), - strcmp(level, KERN_ERR) == 0 ? " *ERROR*" : "", &vaf); - - va_end(args); -} -EXPORT_SYMBOL(drm_printk); - /* * DRM Minors * A DRM device can provide several char-dev interfaces on the DRM-Major. Each diff --git a/include/drm/drmP.h b/include/drm/drmP.h index a9cfd33..680f359 100644 --- a/include/drm/drmP.h +++ b/include/drm/drmP.h @@ -58,6 +58,7 @@ #include #include #include +#include #include #include @@ -129,7 +130,6 @@ struct dma_buf_attachment; * run-time by echoing the debug value in its sysfs node: * # echo 0xf > /sys/module/drm/parameters/debug */ -#define DRM_UT_NONE 0x00 #define DRM_UT_CORE 0x01 #define DRM_UT_DRIVER 0x02 #define DRM_UT_KMS 0x04 @@ -146,25 +146,22 @@ struct dma_buf_attachment; /** \name Macros to make printk easier */ /*@{*/ -#define _DRM_PRINTK(once, level, fmt, ...) \ - do { \ - printk##once(KERN_##level "[" DRM_NAME "] " fmt, \ - ##__VA_ARGS__); \ - } while (0) +#define _DRM_FMT_PREFIX "[" DRM_NAME "] " +#define _DRM_FMT_FUNC_PREFIX "[" DRM_NAME ":%s] " #define DRM_INFO(fmt, ...) \ - _DRM_PRINTK(, INFO, fmt, ##__VA_ARGS__) + pr_info(_DRM_FMT_PREFIX fmt, ##__VA_ARGS__) #define DRM_NOTE(fmt, ...) \ - _DRM_PRINTK(, NOTICE, fmt, ##__VA_ARGS__) + pr_notice(_DRM_FMT_PREFIX fmt, ##__VA_ARGS__) #define DRM_WARN(fmt, ...) \ - _DRM_PRINTK(, WARNING, fmt, ##__VA_ARGS__) + pr_warn(_DRM_FMT_PREFIX fmt, ##__VA_ARGS__) #define DRM_INFO_ONCE(fmt, ...) \ - _DRM_PRINTK(_once, INFO, fmt, ##__VA_ARGS__) + pr_info_once(_DRM_FMT_PREFIX fmt, ##__VA_ARGS__) #define DRM_NOTE_ONCE(fmt, ...) \ - _DRM_PRINTK(_once, NOTICE, fmt, ##__VA_ARGS__) + pr_notice_once(_DRM_FMT_PREFIX fmt, ##__VA_ARGS__) #define DRM_WARN_ONCE(fmt, ...) \ - _DRM_PRINTK(_once, WARNING, fmt, ##__VA_ARGS__) + pr_warn_once(_DRM_FMT_PREFIX fmt, ##__VA_ARGS__) /** * Error output. @@ -173,10 +170,11 @@ struct dma_buf_attachment; * \param arg arguments */ #define DRM_DEV_ERROR(dev, fmt, ...) \ - drm_dev_printk(dev, KERN_ERR, DRM_UT_NONE, __func__, " *ERROR*",\ - fmt, ##__VA_ARGS__) + dev_err(dev, _DRM_FMT_FUNC_PREFIX "*ERROR*" fmt, __func__, \ + ##__VA_ARGS__) #define DRM_ERROR(fmt, ...) \ - drm_printk(KERN_ERR, DRM_UT_NONE, fmt, ##__VA_ARGS__) + pr_err(_DRM_FMT_FUNC_PREFIX "*ERROR*" fmt, __func__, \ + ##__VA_ARGS__) /** * Rate limited error output. Like DRM_ERROR() but won't flood the log. @@ -193,21 +191,14 @@ struct dma_buf_attachment; if (__ratelimit(&_rs)) \ DRM_DEV_ERROR(dev, fmt, ##__VA_ARGS__); \ }) -#define DRM_ERROR_RATELIMITED(fmt, ...) \ - DRM_DEV_ERROR_RATELIMITED(NULL, fmt, ##__VA_ARGS__) +#define DRM_ERROR_RATELIMITED(fmt, args...) \ + DRM_DEV_ERROR_RATELIMITED(NULL, fmt, ##args) -#define DRM_DEV_INFO(dev, fmt, ...) \ - drm_dev_printk(dev, KERN_INFO, DRM_UT_NONE, __func__, "", fmt, \ - ##__VA_ARGS__) +#define DRM_DEV_INFO(dev, fmt, args...) \ + dev_info(dev, _DRM_FMT_FUNC_PREFIX fmt, __func__, ##args) -#define DRM_DEV_INFO_ONCE(dev, fmt, ...) \ -({ \ - static bool __print_once __read_mostly; \ - if (!__print_once) { \ - __print_once = true; \ - DRM_DEV_INFO(dev, fmt, ##__VA_ARGS__); \ - } \ -}) +#define DRM_DEV_INFO_ONCE(dev, fmt, args...) \ + dev_info_once(dev, _DRM_FMT_FUNC_PREFIX fmt, __func__, ##args) /** * Debug output. @@ -215,50 +206,104 @@ struct dma_buf_attachment; * \param fmt printf() like format string. * \param arg arguments */ + +#if defined(CONFIG_DYNAMIC_DEBUG) +/* We don't use pr_debug and dev_dbg directly since we want to + * maintain format compatibility with non-dynamic drm debug messages + */ +#define _DRM_DYNAMIC_DEV_DEBUG(dev, fmt, args...) \ +({ \ + DEFINE_DYNAMIC_DEBUG_METADATA(descriptor, fmt); \ + if (DYNAMIC_DEBUG_BRANCH(descriptor)) \ + dev_printk(KERN_DEBUG, dev, fmt, ##args); \ +}) +#define _DRM_DYNAMIC_DEBUG(fmt, args...) \ +({ \ + DEFINE_DYNAMIC_DEBUG_METADATA(descriptor, fmt); \ + if (DYNAMIC_DEBUG_BRANCH(descriptor)) \ + printk(KERN_DEBUG fmt, ##args); \ +}) +#else +#define _DRM_DYNAMIC_DEV_DEBUG(dev, fmt, args...) \ + no_printk(fmt, ##args) +#define _DRM_DYNAMIC_DEBUG(fmt, args...) \ + no_printk(fmt, ##args) +#endif + +/* The conditional use of pr_debug/dev_dbg here allows us to take + * advantage of the kernel's dynamic debug feature by default (ref + * Documentation/dynamic-debug-howto.txt) while maintaining + * compatibility with using drm.drm_debug to turn on sets of messages + * + * Note: pr_debug and dev_dbg can't be called by a wrapper function + * otherwise they can't track the __FILE__, __func__ and __LINE__ + * where they are called. + */ +#define _DRM_DEV_DEBUG(dev, category, fmt, args...) \ +({ \ + if (unlikely(drm_debug & category)) { \ + dev_printk(KERN_DEBUG, dev, _DRM_FMT_FUNC_PREFIX fmt, \ + __func__, ##args); \ + } else { \ + _DRM_DYNAMIC_DEV_DEBUG(dev, _DRM_FMT_FUNC_PREFIX fmt, \ + __func__, ##args); \ + } \ +}) +#define _DRM_DEBUG(category, fmt, args...) \ +({ \ + if (unlikely(drm_debug & category)) { \ + printk(KERN_DEBUG _DRM_FMT_FUNC_PREFIX fmt, \ + __func__, ##args); \ + } else \ + _DRM_DYNAMIC_DEBUG(_DRM_FMT_FUNC_PREFIX fmt, \ + __func__, ##args); \ +}) + #define DRM_DEV_DEBUG(dev, fmt, args...) \ - drm_dev_printk(dev, KERN_DEBUG, DRM_UT_CORE, __func__, "", fmt, \ - ##args) -#define DRM_DEBUG(fmt, ...) \ - drm_printk(KERN_DEBUG, DRM_UT_CORE, fmt, ##__VA_ARGS__) + _DRM_DEV_DEBUG(dev, DRM_UT_CORE, fmt, ##args) +#define DRM_DEBUG(fmt, args...) \ + _DRM_DEBUG(DRM_UT_CORE, fmt, ##args) #define DRM_DEV_DEBUG_DRIVER(dev, fmt, args...) \ - drm_dev_printk(dev, KERN_DEBUG, DRM_UT_DRIVER, __func__, "", \ - fmt, ##args) -#define DRM_DEBUG_DRIVER(fmt, ...) \ - drm_printk(KERN_DEBUG, DRM_UT_DRIVER, fmt, ##__VA_ARGS__) + _DRM_DEV_DEBUG(dev, DRM_UT_DRIVER, fmt, ##args) +#define DRM_DEBUG_DRIVER(fmt, args...) \ + _DRM_DEBUG(DRM_UT_DRIVER, fmt, ##args) #define DRM_DEV_DEBUG_KMS(dev, fmt, args...) \ - drm_dev_printk(dev, KERN_DEBUG, DRM_UT_KMS, __func__, "", fmt, \ - ##args) -#define DRM_DEBUG_KMS(fmt, ...) \ - drm_printk(KERN_DEBUG, DRM_UT_KMS, fmt, ##__VA_ARGS__) + _DRM_DEV_DEBUG(dev, DRM_UT_KMS, fmt, ##args) +#define DRM_DEBUG_KMS(fmt, args...) \ + _DRM_DEBUG(DRM_UT_KMS, fmt, ##args) #define DRM_DEV_DEBUG_PRIME(dev, fmt, args...) \ - drm_dev_printk(dev, KERN_DEBUG, DRM_UT_PRIME, __func__, "", \ - fmt, ##args) -#define DRM_DEBUG_PRIME(fmt, ...) \ - drm_printk(KERN_DEBUG, DRM_UT_PRIME, fmt, ##__VA_ARGS__) + _DRM_DEV_DEBUG(dev, DRM_UT_PRIME, fmt, ##args) +#define DRM_DEBUG_PRIME(fmt, args...) \ + _DRM_DEBUG(DRM_UT_PRIME, fmt, ##args) #define DRM_DEV_DEBUG_ATOMIC(dev, fmt, args...) \ - drm_dev_printk(dev, KERN_DEBUG, DRM_UT_ATOMIC, __func__, "", \ - fmt, ##args) -#define DRM_DEBUG_ATOMIC(fmt, ...) \ - drm_printk(KERN_DEBUG, DRM_UT_ATOMIC, fmt, ##__VA_ARGS__) + _DRM_DEV_DEBUG(dev, DRM_UT_ATOMIC, fmt, ##args) +#define DRM_DEBUG_ATOMIC(fmt, args...) \ + _DRM_DEBUG(DRM_UT_ATOMIC, fmt, ##args) #define DRM_DEV_DEBUG_VBL(dev, fmt, args...) \ - drm_dev_printk(dev, KERN_DEBUG, DRM_UT_VBL, __func__, "", fmt, \ - ##args) -#define DRM_DEBUG_VBL(fmt, ...) \ - drm_printk(KERN_DEBUG, DRM_UT_VBL, fmt, ##__VA_ARGS__) + _DRM_DEV_DEBUG(dev, DRM_UT_VBL, fmt, ##args) +#define DRM_DEBUG_VBL(fmt, args...) \ + _DRM_DEBUG(DRM_UT_VBL, fmt, ##args) -#define _DRM_DEV_DEFINE_DEBUG_RATELIMITED(dev, level, fmt, args...) \ +#define _DRM_DEV_DEFINE_DEBUG_RATELIMITED(dev, category, fmt, args...) \ +({ \ + static DEFINE_RATELIMIT_STATE(_rs, \ + DEFAULT_RATELIMIT_INTERVAL, \ + DEFAULT_RATELIMIT_BURST); \ + if (__ratelimit(&_rs)) \ + _DRM_DEV_DEBUG(dev, DRM_UT_ ## category, fmt, ##args); \ +}) +#define _DRM_DEFINE_DEBUG_RATELIMITED(category, fmt, args...) \ ({ \ static DEFINE_RATELIMIT_STATE(_rs, \ DEFAULT_RATELIMIT_INTERVAL, \ DEFAULT_RATELIMIT_BURST); \ if (__ratelimit(&_rs)) \ - drm_dev_printk(dev, KERN_DEBUG, DRM_UT_ ## level, \ - __func__, "", fmt, ##args); \ + _DRM_DEBUG(DRM_UT_ ## category, fmt, ##args); \ }) /** @@ -268,21 +313,24 @@ struct dma_buf_attachment; * \param arg arguments */ #define DRM_DEV_DEBUG_RATELIMITED(dev, fmt, args...) \ - DEV__DRM_DEFINE_DEBUG_RATELIMITED(dev, CORE, fmt, ##args) + _DRM_DEFINE_DEBUG_RATELIMITED(dev, CORE, fmt, ##args) #define DRM_DEBUG_RATELIMITED(fmt, args...) \ - DRM_DEV_DEBUG_RATELIMITED(NULL, fmt, ##args) + _DRM_DEFINE_DEBUG_RATELIMITED(CORE, fmt, ##args) + #define DRM_DEV_DEBUG_DRIVER_RATELIMITED(dev, fmt, args...) \ _DRM_DEV_DEFINE_DEBUG_RATELIMITED(dev, DRIVER, fmt, ##args) #define DRM_DEBUG_DRIVER_RATELIMITED(fmt, args...) \ - DRM_DEV_DEBUG_DRIVER_RATELIMITED(NULL, fmt, ##args) + _DRM_DEV_DEFINE_DEBUG_RATELIMITED(DRIVER, fmt, ##args) + #define DRM_DEV_DEBUG_KMS_RATELIMITED(dev, fmt, args...) \ _DRM_DEV_DEFINE_DEBUG_RATELIMITED(dev, KMS, fmt, ##args) #define DRM_DEBUG_KMS_RATELIMITED(fmt, args...) \ - DRM_DEV_DEBUG_KMS_RATELIMITED(NULL, fmt, ##args) + _DRM_DEFINE_DEBUG_RATELIMITED(KMS, fmt, ##args) + #define DRM_DEV_DEBUG_PRIME_RATELIMITED(dev, fmt, args...) \ _DRM_DEV_DEFINE_DEBUG_RATELIMITED(dev, PRIME, fmt, ##args) #define DRM_DEBUG_PRIME_RATELIMITED(fmt, args...) \ - DRM_DEV_DEBUG_PRIME_RATELIMITED(NULL, fmt, ##args) + _DRM_DEFINE_DEBUG_RATELIMITED(PRIME, fmt, ##args) /* Format strings and argument splitters to simplify printing * various "complex" objects