From: Tvrtko Ursulin tvrtko.ursulin@intel.com
This series tries to solve a few issues in the current DRM logging code to primarily make it clearer which messages belong to which driver.
Main problem is that currently some logging functions allow individual drivers to override the log prefix (since they are defined as macros, or static inlines), while other hardcode the "drm" prefix into them due being situated in the DRM core modules.
Another thing is that I noticed the DRM_NAME macro which is used for this is defined in the uAPI header and had a comment which looked outdated.
Therefore I introduce a new define, called, DRM_LOG_NAME, this time defined internally in the kernel headers and not exported in the uAPI.
I also refactored some logging functions to take this string as a parameter instead of hardcoding it.
Individual drivers can then override this define to make DRM logging functions prefix their message with the respective driver prefix.
End result in the case of the i915 driver looks like this:
Old log:
[drm] Found 128MB of eDRAM [drm:skl_enable_dc6 [i915]] Enabling DC6
New log:
[i915] Found 128MB of eDRAM [i915:skl_enable_dc6 [i915]] Enabling DC6
There is some redundancy in the debug logs, as can be seen in the line above, but this comes from drm_printk printing the calling function name using the %ps formatting specifier and __builtin_return_address. Theoretically we could remove the driver prefix from debug messages, but that would make the messages a bit unusually formatted like:
[skl_enable_dc6 [i915]] Enabling DC6
Better would probably be:
[i915:skl_enable_dc6] Enabling DC6
But I do not know how to achieve that apart from changing the drm_printk wrapper macros to pass in __func__ and drop the __builtin_return_address business. And that would also mean all DRM drivers would have to start defining DRM_LOG_NAME or would lose the module owner info. So I opted not to go that route for now.
Main question is whether people find all this an interesting change or would prefer to leave the logging prefixes as they were, or perhaps do some heavier changes to DRM logging.
Cc: dri-devel@lists.freedesktop.org
Tvrtko Ursulin (6): drm/armada: Simplify drm_dev_init error log drm: Introduce unexported DRM_LOG_NAME define for logging drm/i915: Give our log messages our name drm: Respect driver set DRM_LOG_NAME in drm_printk drm: Respect driver set DRM_LOG_NAME in drm_dev_printk drm: Respect driver set DRM_LOG_NAME in drm_info_printer
drivers/gpu/drm/armada/armada_drv.c | 3 +- drivers/gpu/drm/drm_print.c | 20 ++++++------ drivers/gpu/drm/i915/i915_drv.c | 2 +- drivers/gpu/drm/i915/i915_drv.h | 5 +++ drivers/gpu/drm/i915/intel_display.c | 3 +- include/drm/drm_print.h | 61 +++++++++++++++++++++--------------- include/uapi/drm/drm.h | 2 +- 7 files changed, 55 insertions(+), 41 deletions(-)
From: Tvrtko Ursulin tvrtko.ursulin@intel.com
dev_err will log the device in question and since there is a single caller to drm_dev_init inside this driver, the drm prefix and the function name can both also be safely dropped.
Signed-off-by: Tvrtko Ursulin tvrtko.ursulin@intel.com Cc: Russell King linux@armlinux.org.uk Cc: David Airlie airlied@linux.ie Cc: dri-devel@lists.freedesktop.org --- drivers/gpu/drm/armada/armada_drv.c | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-)
diff --git a/drivers/gpu/drm/armada/armada_drv.c b/drivers/gpu/drm/armada/armada_drv.c index 4b11b6b52f1d..76a06bf6ebcd 100644 --- a/drivers/gpu/drm/armada/armada_drv.c +++ b/drivers/gpu/drm/armada/armada_drv.c @@ -115,8 +115,7 @@ static int armada_drm_bind(struct device *dev)
ret = drm_dev_init(&priv->drm, &armada_drm_driver, dev); if (ret) { - dev_err(dev, "[" DRM_NAME ":%s] drm_dev_init failed: %d\n", - __func__, ret); + dev_err(dev, "drm_dev_init failed: %d\n", ret); kfree(priv); return ret; }
On Wed, Jan 24, 2018 at 04:18:16PM +0000, Tvrtko Ursulin wrote:
From: Tvrtko Ursulin tvrtko.ursulin@intel.com
dev_err will log the device in question and since there is a single caller to drm_dev_init inside this driver, the drm prefix and the function name can both also be safely dropped.
Signed-off-by: Tvrtko Ursulin tvrtko.ursulin@intel.com
Acked-by: Russell King rmk+kernel@armlinux.org.uk
Thanks.
Cc: David Airlie airlied@linux.ie Cc: dri-devel@lists.freedesktop.org
drivers/gpu/drm/armada/armada_drv.c | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-)
diff --git a/drivers/gpu/drm/armada/armada_drv.c b/drivers/gpu/drm/armada/armada_drv.c index 4b11b6b52f1d..76a06bf6ebcd 100644 --- a/drivers/gpu/drm/armada/armada_drv.c +++ b/drivers/gpu/drm/armada/armada_drv.c @@ -115,8 +115,7 @@ static int armada_drm_bind(struct device *dev)
ret = drm_dev_init(&priv->drm, &armada_drm_driver, dev); if (ret) {
dev_err(dev, "[" DRM_NAME ":%s] drm_dev_init failed: %d\n",__func__, ret);
dev_err(dev, "drm_dev_init failed: %d\n", ret);-- 2.14.1
From: Tvrtko Ursulin tvrtko.ursulin@intel.com
Instead of having DRM_NAME which is defined in the uAPI headers used for kernel log prefix messages, introduct a new DRM_LOG_NAME define defined privately in kernel space.
Leave the DRM_NAME around, but mark it as obsolete in case there is some userspace code depending on its presence.
Signed-off-by: Tvrtko Ursulin tvrtko.ursulin@intel.com Cc: Daniel Vetter daniel.vetter@intel.com Cc: Gustavo Padovan gustavo@padovan.org Cc: Sean Paul seanpaul@chromium.org Cc: David Airlie airlied@linux.ie Cc: dri-devel@lists.freedesktop.org --- drivers/gpu/drm/drm_print.c | 6 +++--- drivers/gpu/drm/i915/i915_drv.c | 2 +- include/drm/drm_print.h | 9 ++++++++- include/uapi/drm/drm.h | 2 +- 4 files changed, 13 insertions(+), 6 deletions(-)
diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 781518fd88e3..27244f11c9a3 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -38,7 +38,7 @@ EXPORT_SYMBOL(__drm_printfn_seq_file);
void __drm_printfn_info(struct drm_printer *p, struct va_format *vaf) { - dev_info(p->arg, "[" DRM_NAME "] %pV", vaf); + dev_info(p->arg, "[" DRM_LOG_NAME "] %pV", vaf); } EXPORT_SYMBOL(__drm_printfn_info);
@@ -63,7 +63,7 @@ void drm_printf(struct drm_printer *p, const char *f, ...) } EXPORT_SYMBOL(drm_printf);
-#define DRM_PRINTK_FMT "[" DRM_NAME ":%s]%s %pV" +#define DRM_PRINTK_FMT "[" DRM_LOG_NAME ":%s]%s %pV"
void drm_dev_printk(const struct device *dev, const char *level, unsigned int category, const char *function_name, @@ -102,7 +102,7 @@ void drm_printk(const char *level, unsigned int category, vaf.fmt = format; vaf.va = &args;
- printk("%s" "[" DRM_NAME ":%ps]%s %pV", + printk("%s" "[" DRM_LOG_NAME ":%ps]%s %pV", level, __builtin_return_address(0), strcmp(level, KERN_ERR) == 0 ? " *ERROR*" : "", &vaf);
diff --git a/drivers/gpu/drm/i915/i915_drv.c b/drivers/gpu/drm/i915/i915_drv.c index 1fbe37889d92..915e43aacaa5 100644 --- a/drivers/gpu/drm/i915/i915_drv.c +++ b/drivers/gpu/drm/i915/i915_drv.c @@ -94,7 +94,7 @@ __i915_printk(struct drm_i915_private *dev_priv, const char *level, vaf.fmt = fmt; vaf.va = &args;
- dev_printk(level, kdev, "[" DRM_NAME ":%ps] %pV", + dev_printk(level, kdev, "[" DRM_LOG_NAME ":%ps] %pV", __builtin_return_address(0), &vaf);
if (is_error && !shown_bug_once) { diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index 2a4a42e59a47..d6901128faf2 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -60,6 +60,13 @@ * } */
+/** + * String output in log messages - can be overriden by driver code. + */ +#ifndef DRM_LOG_NAME +#define DRM_LOG_NAME "drm" +#endif + /** * struct drm_printer - drm output "stream" * @@ -208,7 +215,7 @@ void drm_printk(const char *level, unsigned int category,
#define _DRM_PRINTK(once, level, fmt, ...) \ do { \ - printk##once(KERN_##level "[" DRM_NAME "] " fmt, \ + printk##once(KERN_##level "[" DRM_LOG_NAME "] " fmt, \ ##__VA_ARGS__); \ } while (0)
diff --git a/include/uapi/drm/drm.h b/include/uapi/drm/drm.h index 6fdff5945c8a..7b512673c220 100644 --- a/include/uapi/drm/drm.h +++ b/include/uapi/drm/drm.h @@ -69,7 +69,7 @@ typedef unsigned long drm_handle_t; extern "C" { #endif
-#define DRM_NAME "drm" /**< Name in kernel, /dev, and /proc */ +#define DRM_NAME "drm" /**< Deprecated. */ #define DRM_MIN_ORDER 5 /**< At least 2^5 bytes = 32 bytes */ #define DRM_MAX_ORDER 22 /**< Up to 2^22 bytes = 4MB */ #define DRM_RAM_PERCENT 10 /**< How much system ram can we lock? */
From: Tvrtko Ursulin tvrtko.ursulin@intel.com
Define DRM_LOG_NAME to i915 so that the log messages we output change from:
[drm] RC6 on
to:
[i915] RC6 on
Signed-off-by: Tvrtko Ursulin tvrtko.ursulin@intel.com Cc: dri-devel@lists.freedesktop.org --- drivers/gpu/drm/i915/i915_drv.h | 5 +++++ 1 file changed, 5 insertions(+)
diff --git a/drivers/gpu/drm/i915/i915_drv.h b/drivers/gpu/drm/i915/i915_drv.h index 8333692dac5a..2b48a7d2d129 100644 --- a/drivers/gpu/drm/i915/i915_drv.h +++ b/drivers/gpu/drm/i915/i915_drv.h @@ -30,6 +30,11 @@ #ifndef _I915_DRV_H_ #define _I915_DRV_H_
+#ifdef DRM_LOG_NAME +#undef DRM_LOG_NAME +#endif +#define DRM_LOG_NAME "i915" + #include <uapi/drm/i915_drm.h> #include <uapi/drm/drm_fourcc.h>
On Wed, 24 Jan 2018 17:18:18 +0100, Tvrtko Ursulin tursulin@ursulin.net wrote:
From: Tvrtko Ursulin tvrtko.ursulin@intel.com
Define DRM_LOG_NAME to i915 so that the log messages we output change from:
[drm] RC6 on
to:
[i915] RC6 on
Signed-off-by: Tvrtko Ursulin tvrtko.ursulin@intel.com Cc: dri-devel@lists.freedesktop.org
drivers/gpu/drm/i915/i915_drv.h | 5 +++++ 1 file changed, 5 insertions(+)
diff --git a/drivers/gpu/drm/i915/i915_drv.h b/drivers/gpu/drm/i915/i915_drv.h index 8333692dac5a..2b48a7d2d129 100644 --- a/drivers/gpu/drm/i915/i915_drv.h +++ b/drivers/gpu/drm/i915/i915_drv.h @@ -30,6 +30,11 @@ #ifndef _I915_DRV_H_ #define _I915_DRV_H_ +#ifdef DRM_LOG_NAME +#undef DRM_LOG_NAME +#endif +#define DRM_LOG_NAME "i915"
Maybe better option would be to add this definition to our Makefile
subdir-ccflags-y += -DDRM_LOG_NAME="i915"
Note that drm_print.h (patch 2/6) already has proper #ifndef
Michal
#include <uapi/drm/i915_drm.h> #include <uapi/drm/drm_fourcc.h>
On 26/01/2018 13:10, Michal Wajdeczko wrote:
On Wed, 24 Jan 2018 17:18:18 +0100, Tvrtko Ursulin tursulin@ursulin.net wrote:
From: Tvrtko Ursulin tvrtko.ursulin@intel.com
Define DRM_LOG_NAME to i915 so that the log messages we output change from:
[drm] RC6 on
to:
[i915] RC6 on
Signed-off-by: Tvrtko Ursulin tvrtko.ursulin@intel.com Cc: dri-devel@lists.freedesktop.org
drivers/gpu/drm/i915/i915_drv.h | 5 +++++ 1 file changed, 5 insertions(+)
diff --git a/drivers/gpu/drm/i915/i915_drv.h b/drivers/gpu/drm/i915/i915_drv.h index 8333692dac5a..2b48a7d2d129 100644 --- a/drivers/gpu/drm/i915/i915_drv.h +++ b/drivers/gpu/drm/i915/i915_drv.h @@ -30,6 +30,11 @@ #ifndef _I915_DRV_H_ #define _I915_DRV_H_ +#ifdef DRM_LOG_NAME +#undef DRM_LOG_NAME +#endif +#define DRM_LOG_NAME "i915"
Maybe better option would be to add this definition to our Makefile
subdir-ccflags-y += -DDRM_LOG_NAME="i915"
Note that drm_print.h (patch 2/6) already has proper #ifndef
So that is always guaranteed to be included first? Sounds attractive, yep.
Unfortunately series does not seem to improve things sufficiently to garner any interest so I am reluctant to respin with that change.
Regards,
Tvrtko
From: Tvrtko Ursulin tvrtko.ursulin@intel.com
Since drm_printk is built inside the DRM core module, it will not respect the potentially overriden by the driver DRM_LOG_NAME.
Make it tale the driver prefix and change it's wrappers so it is passed in from the driver code. This makes the driver log messages correctly identify from which driver they originated.
For instance i915, instead of:
[drm:edp_panel_off [i915]] Wait for panel power off time
would now log debug messages as:
[i915:edp_panel_off [i915]] Wait for panel power off time
Signed-off-by: Tvrtko Ursulin tvrtko.ursulin@intel.com Cc: Daniel Vetter daniel.vetter@intel.com Cc: Gustavo Padovan gustavo@padovan.org Cc: Sean Paul seanpaul@chromium.org Cc: David Airlie airlied@linux.ie Cc: dri-devel@lists.freedesktop.org --- drivers/gpu/drm/drm_print.c | 6 +++--- drivers/gpu/drm/i915/intel_display.c | 3 ++- include/drm/drm_print.h | 20 ++++++++++---------- 3 files changed, 15 insertions(+), 14 deletions(-)
diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 27244f11c9a3..90d38c830392 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -89,7 +89,7 @@ void drm_dev_printk(const struct device *dev, const char *level, } EXPORT_SYMBOL(drm_dev_printk);
-void drm_printk(const char *level, unsigned int category, +void drm_printk(const char *level, unsigned int category, const char *driver, const char *format, ...) { struct va_format vaf; @@ -102,8 +102,8 @@ void drm_printk(const char *level, unsigned int category, vaf.fmt = format; vaf.va = &args;
- printk("%s" "[" DRM_LOG_NAME ":%ps]%s %pV", - level, __builtin_return_address(0), + printk("%s[%s:%ps]%s %pV", + level, driver, __builtin_return_address(0), strcmp(level, KERN_ERR) == 0 ? " *ERROR*" : "", &vaf);
va_end(args); diff --git a/drivers/gpu/drm/i915/intel_display.c b/drivers/gpu/drm/i915/intel_display.c index d585ce4c8732..51fea2eb1b2e 100644 --- a/drivers/gpu/drm/i915/intel_display.c +++ b/drivers/gpu/drm/i915/intel_display.c @@ -10973,7 +10973,8 @@ pipe_config_err(bool adjust, const char *name, const char *format, ...) vaf.fmt = format; vaf.va = &args;
- drm_printk(level, category, "mismatch in %s %pV", name, &vaf); + drm_printk(level, category, DRM_LOG_NAME, "mismatch in %s %pV", name, + &vaf);
va_end(args); } diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index d6901128faf2..c6047de9cbcc 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -207,8 +207,8 @@ __printf(6, 7) void drm_dev_printk(const struct device *dev, const char *level, unsigned int category, const char *function_name, const char *prefix, const char *format, ...); -__printf(3, 4) -void drm_printk(const char *level, unsigned int category, +__printf(4, 5) +void drm_printk(const char *level, unsigned int category, const char *driver, const char *format, ...);
/* Macros to make printk easier */ @@ -243,7 +243,7 @@ void drm_printk(const char *level, unsigned int category, drm_dev_printk(dev, KERN_ERR, DRM_UT_NONE, __func__, " *ERROR*",\ fmt, ##__VA_ARGS__) #define DRM_ERROR(fmt, ...) \ - drm_printk(KERN_ERR, DRM_UT_NONE, fmt, ##__VA_ARGS__) + drm_printk(KERN_ERR, DRM_UT_NONE, DRM_LOG_NAME, fmt, ##__VA_ARGS__)
/** * Rate limited error output. Like DRM_ERROR() but won't flood the log. @@ -286,40 +286,40 @@ void drm_printk(const char *level, unsigned int category, 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_printk(KERN_DEBUG, DRM_UT_CORE, DRM_LOG_NAME, fmt, ##__VA_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_printk(KERN_DEBUG, DRM_UT_DRIVER, DRM_LOG_NAME, fmt, ##__VA_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_printk(KERN_DEBUG, DRM_UT_KMS, DRM_LOG_NAME, fmt, ##__VA_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_printk(KERN_DEBUG, DRM_UT_PRIME, DRM_LOG_NAME, fmt, ##__VA_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_printk(KERN_DEBUG, DRM_UT_ATOMIC, DRM_LOG_NAME, fmt, ##__VA_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_printk(KERN_DEBUG, DRM_UT_VBL, DRM_LOG_NAME, fmt, ##__VA_ARGS__)
#define DRM_DEBUG_LEASE(fmt, ...) \ - drm_printk(KERN_DEBUG, DRM_UT_LEASE, fmt, ##__VA_ARGS__) + drm_printk(KERN_DEBUG, DRM_UT_LEASE, DRM_LOG_NAME, fmt, ##__VA_ARGS__)
#define _DRM_DEV_DEFINE_DEBUG_RATELIMITED(dev, level, fmt, args...) \ ({ \
From: Tvrtko Ursulin tvrtko.ursulin@intel.com
Same as the previous patch did for drm_printk, allow for the logging macros to pass in the driver set DRM_LOG_NAME for drm_dev_printk.
Signed-off-by: Tvrtko Ursulin tvrtko.ursulin@intel.com Cc: Daniel Vetter daniel.vetter@intel.com Cc: Gustavo Padovan gustavo@padovan.org Cc: Sean Paul seanpaul@chromium.org Cc: David Airlie airlied@linux.ie Cc: dri-devel@lists.freedesktop.org --- drivers/gpu/drm/drm_print.c | 12 ++++++------ include/drm/drm_print.h | 31 ++++++++++++++++--------------- 2 files changed, 22 insertions(+), 21 deletions(-)
diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 90d38c830392..f97bfcb7d882 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -63,11 +63,10 @@ void drm_printf(struct drm_printer *p, const char *f, ...) } EXPORT_SYMBOL(drm_printf);
-#define DRM_PRINTK_FMT "[" DRM_LOG_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, ...) + const char *prefix, const char *driver, + const char *format, ...) { struct va_format vaf; va_list args; @@ -80,10 +79,11 @@ void drm_dev_printk(const struct device *dev, const char *level, vaf.va = &args;
if (dev) - dev_printk(level, dev, DRM_PRINTK_FMT, function_name, prefix, - &vaf); + dev_printk(level, dev, "[%s:%s]%s %pV", driver, function_name, + prefix, &vaf); else - printk("%s" DRM_PRINTK_FMT, level, function_name, prefix, &vaf); + printk("%s[%s:%s]%s %pV", level, driver, function_name, prefix, + &vaf);
va_end(args); } diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index c6047de9cbcc..c4dfcd217bce 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -203,10 +203,11 @@ static inline struct drm_printer drm_debug_printer(const char *prefix) #define DRM_UT_STATE 0x40 #define DRM_UT_LEASE 0x80
-__printf(6, 7) +__printf(7, 8) void drm_dev_printk(const struct device *dev, const char *level, unsigned int category, const char *function_name, - const char *prefix, const char *format, ...); + const char *prefix, const char *driver, const char *format, + ...); __printf(4, 5) void drm_printk(const char *level, unsigned int category, const char *driver, const char *format, ...); @@ -241,7 +242,7 @@ void drm_printk(const char *level, unsigned int category, const char *driver, */ #define DRM_DEV_ERROR(dev, fmt, ...) \ drm_dev_printk(dev, KERN_ERR, DRM_UT_NONE, __func__, " *ERROR*",\ - fmt, ##__VA_ARGS__) + DRM_LOG_NAME, fmt, ##__VA_ARGS__) #define DRM_ERROR(fmt, ...) \ drm_printk(KERN_ERR, DRM_UT_NONE, DRM_LOG_NAME, fmt, ##__VA_ARGS__)
@@ -264,8 +265,8 @@ void drm_printk(const char *level, unsigned int category, const char *driver, DRM_DEV_ERROR_RATELIMITED(NULL, fmt, ##__VA_ARGS__)
#define DRM_DEV_INFO(dev, fmt, ...) \ - drm_dev_printk(dev, KERN_INFO, DRM_UT_NONE, __func__, "", fmt, \ - ##__VA_ARGS__) + drm_dev_printk(dev, KERN_INFO, DRM_UT_NONE, __func__, "", \ + DRM_LOG_NAME, fmt, ##__VA_ARGS__)
#define DRM_DEV_INFO_ONCE(dev, fmt, ...) \ ({ \ @@ -283,38 +284,38 @@ void drm_printk(const char *level, unsigned int category, const char *driver, * @fmt: printf() like format string. */ #define DRM_DEV_DEBUG(dev, fmt, args...) \ - drm_dev_printk(dev, KERN_DEBUG, DRM_UT_CORE, __func__, "", fmt, \ - ##args) + drm_dev_printk(dev, KERN_DEBUG, DRM_UT_CORE, __func__, "", \ + DRM_LOG_NAME, fmt, ##args) #define DRM_DEBUG(fmt, ...) \ drm_printk(KERN_DEBUG, DRM_UT_CORE, DRM_LOG_NAME, fmt, ##__VA_ARGS__)
#define DRM_DEV_DEBUG_DRIVER(dev, fmt, args...) \ drm_dev_printk(dev, KERN_DEBUG, DRM_UT_DRIVER, __func__, "", \ - fmt, ##args) + DRM_LOG_NAME, fmt, ##args) #define DRM_DEBUG_DRIVER(fmt, ...) \ drm_printk(KERN_DEBUG, DRM_UT_DRIVER, DRM_LOG_NAME, fmt, ##__VA_ARGS__)
#define DRM_DEV_DEBUG_KMS(dev, fmt, args...) \ - drm_dev_printk(dev, KERN_DEBUG, DRM_UT_KMS, __func__, "", fmt, \ - ##args) + drm_dev_printk(dev, KERN_DEBUG, DRM_UT_KMS, __func__, "", \ + DRM_LOG_NAME, fmt, ##args) #define DRM_DEBUG_KMS(fmt, ...) \ drm_printk(KERN_DEBUG, DRM_UT_KMS, DRM_LOG_NAME, fmt, ##__VA_ARGS__)
#define DRM_DEV_DEBUG_PRIME(dev, fmt, args...) \ drm_dev_printk(dev, KERN_DEBUG, DRM_UT_PRIME, __func__, "", \ - fmt, ##args) + DRM_LOG_NAME, fmt, ##args) #define DRM_DEBUG_PRIME(fmt, ...) \ drm_printk(KERN_DEBUG, DRM_UT_PRIME, DRM_LOG_NAME, fmt, ##__VA_ARGS__)
#define DRM_DEV_DEBUG_ATOMIC(dev, fmt, args...) \ drm_dev_printk(dev, KERN_DEBUG, DRM_UT_ATOMIC, __func__, "", \ - fmt, ##args) + DRM_LOG_NAME, fmt, ##args) #define DRM_DEBUG_ATOMIC(fmt, ...) \ drm_printk(KERN_DEBUG, DRM_UT_ATOMIC, DRM_LOG_NAME, fmt, ##__VA_ARGS__)
#define DRM_DEV_DEBUG_VBL(dev, fmt, args...) \ - drm_dev_printk(dev, KERN_DEBUG, DRM_UT_VBL, __func__, "", fmt, \ - ##args) + drm_dev_printk(dev, KERN_DEBUG, DRM_UT_VBL, __func__, "" \ + DRM_LOG_NAME, fmt, ##args) #define DRM_DEBUG_VBL(fmt, ...) \ drm_printk(KERN_DEBUG, DRM_UT_VBL, DRM_LOG_NAME, fmt, ##__VA_ARGS__)
@@ -328,7 +329,7 @@ void drm_printk(const char *level, unsigned int category, const char *driver, DEFAULT_RATELIMIT_BURST); \ if (__ratelimit(&_rs)) \ drm_dev_printk(dev, KERN_DEBUG, DRM_UT_ ## level, \ - __func__, "", fmt, ##args); \ + __func__, "", DRM_LOG_NAME, fmt, ##args);\ })
/**
From: Tvrtko Ursulin tvrtko.ursulin@intel.com
Same as the previous patch did for drm_printk, allow for the logging macros to pass in the driver set DRM_LOG_NAME for drm_info_printer.
Signed-off-by: Tvrtko Ursulin tvrtko.ursulin@intel.com Cc: Daniel Vetter daniel.vetter@intel.com Cc: Gustavo Padovan gustavo@padovan.org Cc: Sean Paul seanpaul@chromium.org Cc: David Airlie airlied@linux.ie Cc: dri-devel@lists.freedesktop.org --- drivers/gpu/drm/drm_print.c | 2 +- include/drm/drm_print.h | 1 + 2 files changed, 2 insertions(+), 1 deletion(-)
diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index f97bfcb7d882..1fcc08876f87 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -38,7 +38,7 @@ EXPORT_SYMBOL(__drm_printfn_seq_file);
void __drm_printfn_info(struct drm_printer *p, struct va_format *vaf) { - dev_info(p->arg, "[" DRM_LOG_NAME "] %pV", vaf); + dev_info(p->arg, "[%s] %pV", p->prefix, vaf); } EXPORT_SYMBOL(__drm_printfn_info);
diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index c4dfcd217bce..1f613b49c8f2 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -139,6 +139,7 @@ static inline struct drm_printer drm_info_printer(struct device *dev) struct drm_printer p = { .printfn = __drm_printfn_info, .arg = dev, + .prefix = DRM_LOG_NAME, }; return p; }
Quoting Tvrtko Ursulin (2018-01-24 16:18:15)
From: Tvrtko Ursulin tvrtko.ursulin@intel.com
This series tries to solve a few issues in the current DRM logging code to primarily make it clearer which messages belong to which driver.
Main problem is that currently some logging functions allow individual drivers to override the log prefix (since they are defined as macros, or static inlines), while other hardcode the "drm" prefix into them due being situated in the DRM core modules.
Another thing is that I noticed the DRM_NAME macro which is used for this is defined in the uAPI header and had a comment which looked outdated.
Therefore I introduce a new define, called, DRM_LOG_NAME, this time defined internally in the kernel headers and not exported in the uAPI.
I also refactored some logging functions to take this string as a parameter instead of hardcoding it.
Individual drivers can then override this define to make DRM logging functions prefix their message with the respective driver prefix.
End result in the case of the i915 driver looks like this:
Old log:
[drm] Found 128MB of eDRAM [drm:skl_enable_dc6 [i915]] Enabling DC6
New log:
[i915] Found 128MB of eDRAM [i915:skl_enable_dc6 [i915]] Enabling DC6
And still not conforming to the standard logging string. DRM_LOG should be killed off as an anachronistic OS compat layer. -Chris
On 24/01/2018 16:23, Chris Wilson wrote:
Quoting Tvrtko Ursulin (2018-01-24 16:18:15)
From: Tvrtko Ursulin tvrtko.ursulin@intel.com
This series tries to solve a few issues in the current DRM logging code to primarily make it clearer which messages belong to which driver.
Main problem is that currently some logging functions allow individual drivers to override the log prefix (since they are defined as macros, or static inlines), while other hardcode the "drm" prefix into them due being situated in the DRM core modules.
Another thing is that I noticed the DRM_NAME macro which is used for this is defined in the uAPI header and had a comment which looked outdated.
Therefore I introduce a new define, called, DRM_LOG_NAME, this time defined internally in the kernel headers and not exported in the uAPI.
I also refactored some logging functions to take this string as a parameter instead of hardcoding it.
Individual drivers can then override this define to make DRM logging functions prefix their message with the respective driver prefix.
End result in the case of the i915 driver looks like this:
Old log:
[drm] Found 128MB of eDRAM [drm:skl_enable_dc6 [i915]] Enabling DC6
New log:
[i915] Found 128MB of eDRAM [i915:skl_enable_dc6 [i915]] Enabling DC6
And still not conforming to the standard logging string. DRM_LOG should
What is the standard logging string? the dev_ one?
be killed off as an anachronistic OS compat layer.
You mean only dev variants should be kept?
Regards,
Tvrtko
On Wed, 24 Jan 2018, Tvrtko Ursulin tvrtko.ursulin@linux.intel.com wrote:
On 24/01/2018 16:23, Chris Wilson wrote:
Quoting Tvrtko Ursulin (2018-01-24 16:18:15)
From: Tvrtko Ursulin tvrtko.ursulin@intel.com
This series tries to solve a few issues in the current DRM logging code to primarily make it clearer which messages belong to which driver.
Main problem is that currently some logging functions allow individual drivers to override the log prefix (since they are defined as macros, or static inlines), while other hardcode the "drm" prefix into them due being situated in the DRM core modules.
Another thing is that I noticed the DRM_NAME macro which is used for this is defined in the uAPI header and had a comment which looked outdated.
Therefore I introduce a new define, called, DRM_LOG_NAME, this time defined internally in the kernel headers and not exported in the uAPI.
I also refactored some logging functions to take this string as a parameter instead of hardcoding it.
Individual drivers can then override this define to make DRM logging functions prefix their message with the respective driver prefix.
End result in the case of the i915 driver looks like this:
Old log:
[drm] Found 128MB of eDRAM [drm:skl_enable_dc6 [i915]] Enabling DC6
New log:
[i915] Found 128MB of eDRAM [i915:skl_enable_dc6 [i915]] Enabling DC6
And still not conforming to the standard logging string. DRM_LOG should
What is the standard logging string? the dev_ one?
be killed off as an anachronistic OS compat layer.
You mean only dev variants should be kept?
I think the DRM_LOG_NAME override mechanism is too fragile, as it depends on #include ordering. For our driver, I think it basically means always including one of our headers (i915_drv.h) first everywhere (to have a single point of truth for DRM_LOG_NAME), and including drm_print.h first from there. That's not currently true, and I don't want to see a massive #include reordering patchset to make it so.
This is like pr_fmt() which I think has been a mistake and should not be repeated.
I think the direction to go is using dev_printk, dev_dbg, dev_err, dev_warn, and friends, which use dev_driver_string internally. We already have some drm wrappers for those. The problem with them is passing dev, and I think that's the problem we should think about.
We also seem to have opted to use drm_dev_printk (which calls dev_printk or printk) for DRM_DEV_DEBUG and friends. This is arguably a bad choice, because using dev_dbg would let us make use of dynamic debug.
BR, Jani.
Regards,
Tvrtko
Intel-gfx mailing list Intel-gfx@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/intel-gfx
On 25/01/2018 11:32, Jani Nikula wrote:
On Wed, 24 Jan 2018, Tvrtko Ursulin tvrtko.ursulin@linux.intel.com wrote:
On 24/01/2018 16:23, Chris Wilson wrote:
Quoting Tvrtko Ursulin (2018-01-24 16:18:15)
From: Tvrtko Ursulin tvrtko.ursulin@intel.com
This series tries to solve a few issues in the current DRM logging code to primarily make it clearer which messages belong to which driver.
Main problem is that currently some logging functions allow individual drivers to override the log prefix (since they are defined as macros, or static inlines), while other hardcode the "drm" prefix into them due being situated in the DRM core modules.
Another thing is that I noticed the DRM_NAME macro which is used for this is defined in the uAPI header and had a comment which looked outdated.
Therefore I introduce a new define, called, DRM_LOG_NAME, this time defined internally in the kernel headers and not exported in the uAPI.
I also refactored some logging functions to take this string as a parameter instead of hardcoding it.
Individual drivers can then override this define to make DRM logging functions prefix their message with the respective driver prefix.
End result in the case of the i915 driver looks like this:
Old log:
[drm] Found 128MB of eDRAM [drm:skl_enable_dc6 [i915]] Enabling DC6
New log:
[i915] Found 128MB of eDRAM [i915:skl_enable_dc6 [i915]] Enabling DC6
And still not conforming to the standard logging string. DRM_LOG should
What is the standard logging string? the dev_ one?
be killed off as an anachronistic OS compat layer.
You mean only dev variants should be kept?
I think the DRM_LOG_NAME override mechanism is too fragile, as it depends on #include ordering. For our driver, I think it basically means always including one of our headers (i915_drv.h) first everywhere (to have a single point of truth for DRM_LOG_NAME), and including drm_print.h first from there. That's not currently true, and I don't want to see a massive #include reordering patchset to make it so.
This is like pr_fmt() which I think has been a mistake and should not be repeated.
I think the direction to go is using dev_printk, dev_dbg, dev_err, dev_warn, and friends, which use dev_driver_string internally. We already have some drm wrappers for those. The problem with them is passing dev, and I think that's the problem we should think about.
We also seem to have opted to use drm_dev_printk (which calls dev_printk or printk) for DRM_DEV_DEBUG and friends. This is arguably a bad choice, because using dev_dbg would let us make use of dynamic debug.
I agree the current state is messy and that a better improvement could be made. And that the macro string approach is ugly.
To my defence, it sounded like a smaller amount of work to make it at least a little bit better. The way I implemented it, as long as the define is before any include directives it will work as expected. And on my T460p which has both nouveau and i915 it makes the kernel log a bit less confusing. But yeah, it is a marginal user base.
Scratch this then, previous posting was only two years ago so it can wait some more for a more thorough etc rework.
Regards,
Tvrtko
dri-devel@lists.freedesktop.org
-
Chris Wilson -
Jani Nikula -
Michal Wajdeczko -
Russell King - ARM Linux -
Tvrtko Ursulin -
Tvrtko Ursulin