[PATCH v5 00/13] drm/trace: Mirror DRM debug logs to tracefs

List overview All Threads
Download

newer

older

KASAN: vmalloc-out-of-bounds Write...

[PATCH 5.7 252/265]...

Sean Paul

8 Jun 2020 8 Jun '20

9:04 p.m.

From: Sean Paul seanpaul@chromium.org

This series is the latest in my journey to create a lightweight, always-on "flight recorder" (name credit Weston) of drm logs. This incarnation uses a trace_array to keep logs in memory exposed through tracefs. Users and distros can enable drm logs by using the drm.trace module parameter to choose the debug categories they are interested in.

The set has ballooned a little bit since the last version. Reason being is that I decided to return true from drm_debug_enabled if trace was enabled. This should make it easier and more seamless for driver developers to use the correct interface, but meant I needed to audit all uses of drm_debug_enabled and drm_debug_printer.

Out of all those calls, there are 3 situations which arose: 1- The logs should only go to syslog: I've converted these to use the drm_debug_syslog variant of enable check/printer.

2- The logs should go to both syslog/trace, but were using pr_debug(): I've converted these to use the proper drm logging helper. In cases which used a drm_printer I've had to use a new drm_debug_category_printer to ensure they are routed correctly.

3- The logs should go to both syslog/trace and are using drm logging fns: These are untouched and should be routed to the appropriate place(s)

Sean Paul (13): drm/mipi_dbi: Convert pr_debug calls to DRM_DEBUG_DRIVER drm/sil164: Convert dev_printk to drm_dev_dbg drm/i915/utils: Replace dev_printk with drm helpers drm/msm/dpu: Replace definitions for dpu debug macros drm/print: rename drm_debug* to be more syslog-centric drm/amd: Gate i2c transaction logs on drm_debug_syslog drm/etnaviv: Change buffer dump checks to target syslog drm/nouveau: Change debug checks to specifically target syslog drm/i915: Change infoframe debug checks to specify syslog drm/print: Add drm_debug_category_printer drm/mst: Convert debug printers to debug category printers drm/i915: Use debug category printer for welcome message drm/print: Add tracefs support to the drm logging helpers

Documentation/gpu/drm-uapi.rst | 6 + drivers/gpu/drm/amd/amdgpu/smu_v11_0_i2c.c | 4 +- drivers/gpu/drm/drm_dp_mst_topology.c | 9 +- drivers/gpu/drm/drm_drv.c | 3 + drivers/gpu/drm/drm_mipi_dbi.c | 8 +- drivers/gpu/drm/drm_print.c | 228 ++++++++++++++++--- drivers/gpu/drm/etnaviv/etnaviv_buffer.c | 8 +- drivers/gpu/drm/i2c/sil164_drv.c | 12 +- drivers/gpu/drm/i915/display/intel_display.c | 4 +- drivers/gpu/drm/i915/i915_drv.c | 3 +- drivers/gpu/drm/i915/i915_utils.c | 5 +- drivers/gpu/drm/msm/disp/dpu1/dpu_kms.h | 20 +- drivers/gpu/drm/nouveau/dispnv50/disp.h | 4 +- drivers/gpu/drm/nouveau/nouveau_drv.h | 4 +- include/drm/drm_print.h | 96 +++++++- 15 files changed, 318 insertions(+), 96 deletions(-)

-- Sean Paul, Software Engineer, Google / Chromium OS

Show replies by date

Sean Paul

8 Jun 8 Jun

9:04 p.m.

New subject: [PATCH v5 01/13] drm/mipi_dbi: Convert pr_debug calls to DRM_DEBUG_DRIVER

From: Sean Paul seanpaul@chromium.org

Use the drm logging helpers to output these messages to ensure they'll be included by the drm tracefs instance.

Signed-off-by: Sean Paul seanpaul@chromium.org

Changes in v5: -Added to the set --- drivers/gpu/drm/drm_mipi_dbi.c | 8 ++------ 1 file changed, 2 insertions(+), 6 deletions(-)

diff --git a/drivers/gpu/drm/drm_mipi_dbi.c b/drivers/gpu/drm/drm_mipi_dbi.c index fd8d672972a9..ff6f83eeee09 100644 --- a/drivers/gpu/drm/drm_mipi_dbi.c +++ b/drivers/gpu/drm/drm_mipi_dbi.c @@ -769,9 +769,7 @@ static int mipi_dbi_spi1e_transfer(struct mipi_dbi *dbi, int dc, int i, ret; u8 *dst;

- if (drm_debug_enabled(DRM_UT_DRIVER)) - pr_debug("[drm:%s] dc=%d, max_chunk=%zu, transfers:\n", - __func__, dc, max_chunk); + DRM_DEBUG_DRIVER("dc=%d, max_chunk=%zu, transfers:\n", dc, max_chunk);

tr.speed_hz = mipi_dbi_spi_cmd_max_speed(spi, len); spi_message_init_with_transfers(&m, &tr, 1); @@ -893,9 +891,7 @@ static int mipi_dbi_spi1_transfer(struct mipi_dbi *dbi, int dc, max_chunk = dbi->tx_buf9_len; dst16 = dbi->tx_buf9;

- if (drm_debug_enabled(DRM_UT_DRIVER)) - pr_debug("[drm:%s] dc=%d, max_chunk=%zu, transfers:\n", - __func__, dc, max_chunk); + DRM_DEBUG_DRIVER("dc=%d, max_chunk=%zu, transfers:\n", dc, max_chunk);

max_chunk = min(max_chunk / 2, len);

-- Sean Paul, Software Engineer, Google / Chromium OS

Sam Ravnborg

9 Jun 9 Jun

6:28 p.m.

New subject: [PATCH v5 01/13] drm/mipi_dbi: Convert pr_debug calls to DRM_DEBUG_DRIVER

Hi Sean Paul. On Mon, Jun 08, 2020 at 05:04:51PM -0400, Sean Paul wrote:

...

From: Sean Paul seanpaul@chromium.org

Use the drm logging helpers to output these messages to ensure they'll be included by the drm tracefs instance.

Signed-off-by: Sean Paul seanpaul@chromium.org

Changes in v5:

-Added to the set

drivers/gpu/drm/drm_mipi_dbi.c | 8 ++------ 1 file changed, 2 insertions(+), 6 deletions(-)

diff --git a/drivers/gpu/drm/drm_mipi_dbi.c b/drivers/gpu/drm/drm_mipi_dbi.c index fd8d672972a9..ff6f83eeee09 100644 --- a/drivers/gpu/drm/drm_mipi_dbi.c +++ b/drivers/gpu/drm/drm_mipi_dbi.c @@ -769,9 +769,7 @@ static int mipi_dbi_spi1e_transfer(struct mipi_dbi *dbi, int dc, int i, ret; u8 *dst;
if (drm_debug_enabled(DRM_UT_DRIVER))
pr_debug("[drm:%s] dc=%d, max_chunk=%zu, transfers:\n",
	 __func__, dc, max_chunk);
DRM_DEBUG_DRIVER("dc=%d, max_chunk=%zu, transfers:\n", dc, max_chunk);

Today we have drm_dbg(...) as the preferred logging method.

Sam

...

tr.speed_hz = mipi_dbi_spi_cmd_max_speed(spi, len); spi_message_init_with_transfers(&m, &tr, 1); @@ -893,9 +891,7 @@ static int mipi_dbi_spi1_transfer(struct mipi_dbi *dbi, int dc, max_chunk = dbi->tx_buf9_len; dst16 = dbi->tx_buf9;
if (drm_debug_enabled(DRM_UT_DRIVER))
pr_debug("[drm:%s] dc=%d, max_chunk=%zu, transfers:\n",
	 __func__, dc, max_chunk);
DRM_DEBUG_DRIVER("dc=%d, max_chunk=%zu, transfers:\n", dc, max_chunk);

max_chunk = min(max_chunk / 2, len);

-- Sean Paul, Software Engineer, Google / Chromium OS

dri-devel mailing list dri-devel@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/dri-devel

Sean Paul

8 Jun 8 Jun

9:04 p.m.

New subject: [PATCH v5 02/13] drm/sil164: Convert dev_printk to drm_dev_dbg

From: Sean Paul seanpaul@chromium.org

Use the drm debug helper instead of dev_printk in order to leverage the upcoming tracefs support

Signed-off-by: Sean Paul seanpaul@chromium.org

Changes in v5: -Added to the set --- drivers/gpu/drm/i2c/sil164_drv.c | 12 ++++-------- 1 file changed, 4 insertions(+), 8 deletions(-)

diff --git a/drivers/gpu/drm/i2c/sil164_drv.c b/drivers/gpu/drm/i2c/sil164_drv.c index 741886b54419..b315a789fca2 100644 --- a/drivers/gpu/drm/i2c/sil164_drv.c +++ b/drivers/gpu/drm/i2c/sil164_drv.c @@ -43,11 +43,6 @@ struct sil164_priv { #define to_sil164_priv(x) \ ((struct sil164_priv *)to_encoder_slave(x)->slave_priv)

-#define sil164_dbg(client, format, ...) do { \ - if (drm_debug_enabled(DRM_UT_KMS)) \ - dev_printk(KERN_DEBUG, &client->dev, \ - "%s: " format, __func__, ## __VA_ARGS__); \ - } while (0) #define sil164_info(client, format, ...) \ dev_info(&client->dev, format, __VA_ARGS__) #define sil164_err(client, format, ...) \ @@ -359,8 +354,8 @@ sil164_probe(struct i2c_client *client, const struct i2c_device_id *id) int rev = sil164_read(client, SIL164_REVISION);

if (vendor != 0x1 || device != 0x6) { - sil164_dbg(client, "Unknown device %x:%x.%x\n", - vendor, device, rev); + drm_dev_dbg(&client->dev, DRM_UT_KMS, + "Unknown device %x:%x.%x\n", vendor, device, rev); return -ENODEV; }

@@ -389,7 +384,8 @@ sil164_detect_slave(struct i2c_client *client) };

if (i2c_transfer(adap, &msg, 1) != 1) { - sil164_dbg(adap, "No dual-link slave found."); + drm_dev_dbg(&adap->dev, DRM_UT_KMS, + "No dual-link slave found."); return NULL; }

-- Sean Paul, Software Engineer, Google / Chromium OS

Sean Paul

9:04 p.m.

New subject: [PATCH v5 03/13] drm/i915/utils: Replace dev_printk with drm helpers

From: Sean Paul seanpaul@chromium.org

Use drm logging helpers to add support for the upcoming tracefs implementation.

Signed-off-by: Sean Paul seanpaul@chromium.org

Changes in v5: -Added to the set --- drivers/gpu/drm/i915/i915_utils.c | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-)

diff --git a/drivers/gpu/drm/i915/i915_utils.c b/drivers/gpu/drm/i915/i915_utils.c index f42a9e9a0b4f..99499c0885cf 100644 --- a/drivers/gpu/drm/i915/i915_utils.c +++ b/drivers/gpu/drm/i915/i915_utils.c @@ -30,10 +30,9 @@ __i915_printk(struct drm_i915_private *dev_priv, const char *level, vaf.va = &args;

if (is_error) - dev_printk(level, kdev, "%pV", &vaf); + drm_dev_printk(kdev, level, "%pV", &vaf); else - dev_printk(level, kdev, "[" DRM_NAME ":%ps] %pV", - __builtin_return_address(0), &vaf); + drm_err(&dev_priv->drm, "%pV", &vaf);

va_end(args);

-- Sean Paul, Software Engineer, Google / Chromium OS

Sean Paul

9:04 p.m.

New subject: [PATCH v5 04/13] drm/msm/dpu: Replace definitions for dpu debug macros

From: Sean Paul seanpaul@chromium.org

The debug messages shouldn't be logged as errors when debug categories are enabled. Use the drm logging helpers to do the right thing

Signed-off-by: Sean Paul seanpaul@chromium.org

Changes in v5: -Added to the set --- drivers/gpu/drm/msm/disp/dpu1/dpu_kms.h | 20 ++++---------------- 1 file changed, 4 insertions(+), 16 deletions(-)

diff --git a/drivers/gpu/drm/msm/disp/dpu1/dpu_kms.h b/drivers/gpu/drm/msm/disp/dpu1/dpu_kms.h index 4e32d040f1e6..89c444ec3bb8 100644 --- a/drivers/gpu/drm/msm/disp/dpu1/dpu_kms.h +++ b/drivers/gpu/drm/msm/disp/dpu1/dpu_kms.h @@ -29,27 +29,15 @@ * DPU_DEBUG - macro for kms/plane/crtc/encoder/connector logs * @fmt: Pointer to format string */ -#define DPU_DEBUG(fmt, ...) \ - do { \ - if (drm_debug_enabled(DRM_UT_KMS)) \ - DRM_DEBUG(fmt, ##__VA_ARGS__); \ - else \ - pr_debug(fmt, ##__VA_ARGS__); \ - } while (0) +#define DPU_DEBUG(fmt, ...) DRM_DEBUG_KMS(fmt, ##__VA_ARGS__)

/** * DPU_DEBUG_DRIVER - macro for hardware driver logging * @fmt: Pointer to format string */ -#define DPU_DEBUG_DRIVER(fmt, ...) \ - do { \ - if (drm_debug_enabled(DRM_UT_DRIVER)) \ - DRM_ERROR(fmt, ##__VA_ARGS__); \ - else \ - pr_debug(fmt, ##__VA_ARGS__); \ - } while (0) - -#define DPU_ERROR(fmt, ...) pr_err("[dpu error]" fmt, ##__VA_ARGS__) +#define DPU_DEBUG_DRIVER(fmt, ...) DRM_DEBUG_DRIVER(fmt, ##__VA_ARGS__) + +#define DPU_ERROR(fmt, ...) DRM_ERROR(fmt, ##__VA_ARGS__)

/** * ktime_compare_safe - compare two ktime structures

-- Sean Paul, Software Engineer, Google / Chromium OS

Sean Paul

9:04 p.m.

New subject: [PATCH v5 05/13] drm/print: rename drm_debug* to be more syslog-centric

From: Sean Paul seanpaul@chromium.org

In preparation for tracefs support, rename drm_debug related functions to reflect that it targets the syslog. This will allow us to selectively target syslog and/or tracefs.

No functional changes here.

Signed-off-by: Sean Paul seanpaul@chromium.org

Changes in v5: -Added to the set --- drivers/gpu/drm/drm_print.c | 12 ++++++------ include/drm/drm_print.h | 13 +++++++++---- 2 files changed, 15 insertions(+), 10 deletions(-)

diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 111b932cf2a9..2ff7a6ecc632 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -37,11 +37,11 @@ #include <drm/drm_print.h>

/* - * __drm_debug: Enable debug output. + * __drm_debug_syslog: Enable debug output to system logs * Bitmask of DRM_UT_x. See include/drm/drm_print.h for details. */ -unsigned int __drm_debug; -EXPORT_SYMBOL(__drm_debug); +unsigned int __drm_debug_syslog; +EXPORT_SYMBOL(__drm_debug_syslog);

MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug category.\n" "\t\tBit 0 (0x01) will enable CORE messages (drm core code)\n" @@ -52,7 +52,7 @@ MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug cat "\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n" "\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n" "\t\tBit 8 (0x100) will enable DP messages (displayport code)"); -module_param_named(debug, __drm_debug, int, 0600); +module_param_named(debug, __drm_debug_syslog, int, 0600);

void __drm_puts_coredump(struct drm_printer *p, const char *str) { @@ -160,11 +160,11 @@ void __drm_printfn_info(struct drm_printer *p, struct va_format *vaf) } EXPORT_SYMBOL(__drm_printfn_info);

-void __drm_printfn_debug(struct drm_printer *p, struct va_format *vaf) +void __drm_printfn_debug_syslog(struct drm_printer *p, struct va_format *vaf) { pr_debug("%s %pV", p->prefix, vaf); } -EXPORT_SYMBOL(__drm_printfn_debug); +EXPORT_SYMBOL(__drm_printfn_debug_syslog);

void __drm_printfn_err(struct drm_printer *p, struct va_format *vaf) { diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index 1c9417430d08..ce7675bf0d2b 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -35,7 +35,7 @@ #include <drm/drm.h>

/* Do *not* use outside of drm_print.[ch]! */ -extern unsigned int __drm_debug; +extern unsigned int __drm_debug_syslog;

/** * DOC: print @@ -85,7 +85,7 @@ void __drm_puts_coredump(struct drm_printer *p, const char *str); void __drm_printfn_seq_file(struct drm_printer *p, struct va_format *vaf); void __drm_puts_seq_file(struct drm_printer *p, const char *str); void __drm_printfn_info(struct drm_printer *p, struct va_format *vaf); -void __drm_printfn_debug(struct drm_printer *p, struct va_format *vaf); +void __drm_printfn_debug_syslog(struct drm_printer *p, struct va_format *vaf); void __drm_printfn_err(struct drm_printer *p, struct va_format *vaf);

__printf(2, 3) @@ -227,7 +227,7 @@ static inline struct drm_printer drm_info_printer(struct device *dev) static inline struct drm_printer drm_debug_printer(const char *prefix) { struct drm_printer p = { - .printfn = __drm_printfn_debug, + .printfn = __drm_printfn_debug_syslog, .prefix = prefix }; return p; @@ -319,9 +319,14 @@ enum drm_debug_category { DRM_UT_DRMRES = 0x200, };

+static inline bool drm_debug_syslog_enabled(enum drm_debug_category category) +{ + return unlikely(__drm_debug_syslog & category); +} + static inline bool drm_debug_enabled(enum drm_debug_category category) { - return unlikely(__drm_debug & category); + return drm_debug_syslog_enabled(category); }

-- Sean Paul, Software Engineer, Google / Chromium OS

Sean Paul

9:04 p.m.

New subject: [PATCH v5 06/13] drm/amd: Gate i2c transaction logs on drm_debug_syslog

From: Sean Paul seanpaul@chromium.org

Since the logs protected by these checks specifically target syslog, use the new drm_debug_syslog_enabled() call to avoid triggering these prints when only trace is enabled.

Signed-off-by: Sean Paul seanpaul@chromium.org

Changes in v5: -Added to the set --- drivers/gpu/drm/amd/amdgpu/smu_v11_0_i2c.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/drivers/gpu/drm/amd/amdgpu/smu_v11_0_i2c.c b/drivers/gpu/drm/amd/amdgpu/smu_v11_0_i2c.c index 9bffbab35041..9bc6baddd302 100644 --- a/drivers/gpu/drm/amd/amdgpu/smu_v11_0_i2c.c +++ b/drivers/gpu/drm/amd/amdgpu/smu_v11_0_i2c.c @@ -233,7 +233,7 @@ static uint32_t smu_v11_0_i2c_transmit(struct i2c_adapter *control, DRM_DEBUG_DRIVER("I2C_Transmit(), address = %x, bytes = %d , data: ", (uint16_t)address, numbytes);

- if (drm_debug_enabled(DRM_UT_DRIVER)) { + if (drm_debug_syslog_enabled(DRM_UT_DRIVER)) { print_hex_dump(KERN_INFO, "data: ", DUMP_PREFIX_NONE, 16, 1, data, numbytes, false); } @@ -387,7 +387,7 @@ static uint32_t smu_v11_0_i2c_receive(struct i2c_adapter *control, DRM_DEBUG_DRIVER("I2C_Receive(), address = %x, bytes = %d, data :", (uint16_t)address, bytes_received);

- if (drm_debug_enabled(DRM_UT_DRIVER)) { + if (drm_debug_syslog_enabled(DRM_UT_DRIVER)) { print_hex_dump(KERN_INFO, "data: ", DUMP_PREFIX_NONE, 16, 1, data, bytes_received, false); }

-- Sean Paul, Software Engineer, Google / Chromium OS

Christian König

9 Jun 9 Jun

7:10 a.m.

New subject: [PATCH v5 06/13] drm/amd: Gate i2c transaction logs on drm_debug_syslog

Am 08.06.20 um 23:04 schrieb Sean Paul:

...

From: Sean Paul seanpaul@chromium.org

Since the logs protected by these checks specifically target syslog, use the new drm_debug_syslog_enabled() call to avoid triggering these prints when only trace is enabled.

Mhm, of hand that doesn't looks like something which belongs into the syslog in the first place. Maybe convert it into a trace point instead?

...

Signed-off-by: Sean Paul seanpaul@chromium.org

Acked-by: Christian König christian.koenig@amd.com either way.

...

Changes in v5:

-Added to the set

drivers/gpu/drm/amd/amdgpu/smu_v11_0_i2c.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/drivers/gpu/drm/amd/amdgpu/smu_v11_0_i2c.c b/drivers/gpu/drm/amd/amdgpu/smu_v11_0_i2c.c index 9bffbab35041..9bc6baddd302 100644 --- a/drivers/gpu/drm/amd/amdgpu/smu_v11_0_i2c.c +++ b/drivers/gpu/drm/amd/amdgpu/smu_v11_0_i2c.c @@ -233,7 +233,7 @@ static uint32_t smu_v11_0_i2c_transmit(struct i2c_adapter *control, DRM_DEBUG_DRIVER("I2C_Transmit(), address = %x, bytes = %d , data: ", (uint16_t)address, numbytes);

if (drm_debug_enabled(DRM_UT_DRIVER)) {

if (drm_debug_syslog_enabled(DRM_UT_DRIVER)) { print_hex_dump(KERN_INFO, "data: ", DUMP_PREFIX_NONE, 16, 1, data, numbytes, false); }

@@ -387,7 +387,7 @@ static uint32_t smu_v11_0_i2c_receive(struct i2c_adapter *control, DRM_DEBUG_DRIVER("I2C_Receive(), address = %x, bytes = %d, data :", (uint16_t)address, bytes_received);

if (drm_debug_enabled(DRM_UT_DRIVER)) {

if (drm_debug_syslog_enabled(DRM_UT_DRIVER)) { print_hex_dump(KERN_INFO, "data: ", DUMP_PREFIX_NONE, 16, 1, data, bytes_received, false); }

Sean Paul

8 Jun 8 Jun

9:04 p.m.

New subject: [PATCH v5 07/13] drm/etnaviv: Change buffer dump checks to target syslog

From: Sean Paul seanpaul@chromium.org

Since the logs protected by these checks specifically target syslog, use the new drm_debug_syslog_enabled() call to avoid triggering these prints when only trace is enabled.

Signed-off-by: Sean Paul seanpaul@chromium.org

Changes in v5: -Added to the set --- drivers/gpu/drm/etnaviv/etnaviv_buffer.c | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/drivers/gpu/drm/etnaviv/etnaviv_buffer.c b/drivers/gpu/drm/etnaviv/etnaviv_buffer.c index 76d38561c910..7713474800e8 100644 --- a/drivers/gpu/drm/etnaviv/etnaviv_buffer.c +++ b/drivers/gpu/drm/etnaviv/etnaviv_buffer.c @@ -353,7 +353,7 @@ void etnaviv_buffer_queue(struct etnaviv_gpu *gpu, u32 exec_state,

lockdep_assert_held(&gpu->lock);

- if (drm_debug_enabled(DRM_UT_DRIVER)) + if (drm_debug_syslog_enabled(DRM_UT_DRIVER)) etnaviv_buffer_dump(gpu, buffer, 0, 0x50);

link_target = etnaviv_cmdbuf_get_va(cmdbuf, @@ -509,13 +509,13 @@ void etnaviv_buffer_queue(struct etnaviv_gpu *gpu, u32 exec_state, etnaviv_cmdbuf_get_va(buffer, &gpu->mmu_context->cmdbuf_mapping) + buffer->user_size - 4);

- if (drm_debug_enabled(DRM_UT_DRIVER)) + if (drm_debug_syslog_enabled(DRM_UT_DRIVER)) pr_info("stream link to 0x%08x @ 0x%08x %p\n", return_target, etnaviv_cmdbuf_get_va(cmdbuf, &gpu->mmu_context->cmdbuf_mapping), cmdbuf->vaddr);

- if (drm_debug_enabled(DRM_UT_DRIVER)) { + if (drm_debug_syslog_enabled(DRM_UT_DRIVER)) { print_hex_dump(KERN_INFO, "cmd ", DUMP_PREFIX_OFFSET, 16, 4, cmdbuf->vaddr, cmdbuf->size, 0);

@@ -534,6 +534,6 @@ void etnaviv_buffer_queue(struct etnaviv_gpu *gpu, u32 exec_state, VIV_FE_LINK_HEADER_PREFETCH(link_dwords), link_target);

- if (drm_debug_enabled(DRM_UT_DRIVER)) + if (drm_debug_syslog_enabled(DRM_UT_DRIVER)) etnaviv_buffer_dump(gpu, buffer, 0, 0x50); }

-- Sean Paul, Software Engineer, Google / Chromium OS

Sean Paul

9:04 p.m.

New subject: [PATCH v5 08/13] drm/nouveau: Change debug checks to specifically target syslog

From: Sean Paul seanpaul@chromium.org

Since the logs protected by these checks specifically target syslog, use the new drm_debug_syslog_enabled() call to avoid triggering these prints when only trace is enabled.

Signed-off-by: Sean Paul seanpaul@chromium.org

Changes in v5: -Added to the set --- drivers/gpu/drm/nouveau/dispnv50/disp.h | 4 ++-- drivers/gpu/drm/nouveau/nouveau_drv.h | 4 ++-- 2 files changed, 4 insertions(+), 4 deletions(-)

diff --git a/drivers/gpu/drm/nouveau/dispnv50/disp.h b/drivers/gpu/drm/nouveau/dispnv50/disp.h index 696e70a6b98b..d60602db2cf0 100644 --- a/drivers/gpu/drm/nouveau/dispnv50/disp.h +++ b/drivers/gpu/drm/nouveau/dispnv50/disp.h @@ -85,14 +85,14 @@ extern const u64 wndwc57e_modifiers[];

#define evo_mthd(p, m, s) do { \ const u32 _m = (m), _s = (s); \ - if (drm_debug_enabled(DRM_UT_KMS)) \ + if (drm_debug_syslog_enabled(DRM_UT_KMS)) \ pr_err("%04x %d %s\n", _m, _s, __func__); \ *((p)++) = ((_s << 18) | _m); \ } while(0)

#define evo_data(p, d) do { \ const u32 _d = (d); \ - if (drm_debug_enabled(DRM_UT_KMS)) \ + if (drm_debug_syslog_enabled(DRM_UT_KMS)) \ pr_err("\t%08x\n", _d); \ *((p)++) = _d; \ } while(0) diff --git a/drivers/gpu/drm/nouveau/nouveau_drv.h b/drivers/gpu/drm/nouveau/nouveau_drv.h index 2a6519737800..b916d1f456cd 100644 --- a/drivers/gpu/drm/nouveau/nouveau_drv.h +++ b/drivers/gpu/drm/nouveau/nouveau_drv.h @@ -257,11 +257,11 @@ void nouveau_drm_device_remove(struct drm_device *dev); #define NV_INFO(drm,f,a...) NV_PRINTK(info, &(drm)->client, f, ##a)

#define NV_DEBUG(drm,f,a...) do { \ - if (drm_debug_enabled(DRM_UT_DRIVER)) \ + if (drm_debug_syslog_enabled(DRM_UT_DRIVER)) \ NV_PRINTK(info, &(drm)->client, f, ##a); \ } while(0) #define NV_ATOMIC(drm,f,a...) do { \ - if (drm_debug_enabled(DRM_UT_ATOMIC)) \ + if (drm_debug_syslog_enabled(DRM_UT_ATOMIC)) \ NV_PRINTK(info, &(drm)->client, f, ##a); \ } while(0)

-- Sean Paul, Software Engineer, Google / Chromium OS

Sean Paul

9:04 p.m.

New subject: [PATCH v5 09/13] drm/i915: Change infoframe debug checks to specify syslog

From: Sean Paul seanpaul@chromium.org

Since the logs protected by these checks specifically target syslog, use the new drm_debug_syslog_enabled() call to avoid triggering these prints when only trace is enabled.

Signed-off-by: Sean Paul seanpaul@chromium.org

Changes in v5: -Added to the set --- drivers/gpu/drm/i915/display/intel_display.c | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/drivers/gpu/drm/i915/display/intel_display.c b/drivers/gpu/drm/i915/display/intel_display.c index b16aca0fe5f0..de449755d1e5 100644 --- a/drivers/gpu/drm/i915/display/intel_display.c +++ b/drivers/gpu/drm/i915/display/intel_display.c @@ -12876,7 +12876,7 @@ static void intel_dump_infoframe(struct drm_i915_private *dev_priv, const union hdmi_infoframe *frame) { - if (!drm_debug_enabled(DRM_UT_KMS)) + if (!drm_debug_syslog_enabled(DRM_UT_KMS)) return;

hdmi_infoframe_log(KERN_DEBUG, dev_priv->drm.dev, frame); @@ -13519,7 +13519,7 @@ pipe_config_infoframe_mismatch(struct drm_i915_private *dev_priv, const union hdmi_infoframe *b) { if (fastset) { - if (!drm_debug_enabled(DRM_UT_KMS)) + if (!drm_debug_syslog_enabled(DRM_UT_KMS)) return;

drm_dbg_kms(&dev_priv->drm,

-- Sean Paul, Software Engineer, Google / Chromium OS

Sean Paul

9:05 p.m.

New subject: [PATCH v5 10/13] drm/print: Add drm_debug_category_printer

From: Sean Paul seanpaul@chromium.org

This patch adds a new printer which will select the appropriate output for a given debug category. Currently there is only one output target, which is syslog. However in the future we'll have tracefs and it will be useful to print to syslog, tracefs, or both. Drivers just need to create the printer for the appropriate category and the printer will decide where to send the output.

Signed-off-by: Sean Paul seanpaul@chromium.org

Changes in v5: -Added to the set --- drivers/gpu/drm/drm_print.c | 5 +++++ include/drm/drm_print.h | 28 ++++++++++++++++++++++++++++ 2 files changed, 33 insertions(+)

diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 2ff7a6ecc632..4d984a01b3a3 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -172,6 +172,11 @@ void __drm_printfn_err(struct drm_printer *p, struct va_format *vaf) } EXPORT_SYMBOL(__drm_printfn_err);

+void __drm_printfn_noop(struct drm_printer *p, struct va_format *vaf) +{ +} +EXPORT_SYMBOL(__drm_printfn_noop); + /** * drm_puts - print a const string to a &drm_printer stream * @p: the &drm printer diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index ce7675bf0d2b..8987b98bbfda 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -87,6 +87,7 @@ void __drm_puts_seq_file(struct drm_printer *p, const char *str); void __drm_printfn_info(struct drm_printer *p, struct va_format *vaf); void __drm_printfn_debug_syslog(struct drm_printer *p, struct va_format *vaf); void __drm_printfn_err(struct drm_printer *p, struct va_format *vaf); +void __drm_printfn_noop(struct drm_printer *p, struct va_format *vaf);

__printf(2, 3) void drm_printf(struct drm_printer *p, const char *f, ...); @@ -329,6 +330,33 @@ static inline bool drm_debug_enabled(enum drm_debug_category category) return drm_debug_syslog_enabled(category); }

+/** + * drm_debug_category_printer - construct a &drm_printer that outputs to + * pr_debug() if enabled for the given category. + * @category: the DRM_UT_* message category this message belongs to + * @prefix: trace output prefix + * + * RETURNS: + * The &drm_printer object + */ +static inline struct drm_printer +drm_debug_category_printer(enum drm_debug_category category, + const char *prefix) +{ + struct drm_printer p = { + .prefix = prefix + }; + + if (drm_debug_syslog_enabled(category)) { + p.printfn = __drm_printfn_debug_syslog; + } else { + WARN(1, "Debug category %d is inactive.", category); + p.printfn = __drm_printfn_noop; + } + + return p; +} + /* * struct device based logging *

-- Sean Paul, Software Engineer, Google / Chromium OS

Sean Paul

9:05 p.m.

New subject: [PATCH v5 11/13] drm/mst: Convert debug printers to debug category printers

From: Sean Paul seanpaul@chromium.org

The printers in dp_mst are meant to be gated on DRM_UT_DP, so use the debug category printer to avoid dumping mst transactions to the wrong place.

Signed-off-by: Sean Paul seanpaul@chromium.org

Changes in v5: -Added to the set --- drivers/gpu/drm/drm_dp_mst_topology.c | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-)

diff --git a/drivers/gpu/drm/drm_dp_mst_topology.c b/drivers/gpu/drm/drm_dp_mst_topology.c index 1bdf3cfeeebb..e225a84da96e 100644 --- a/drivers/gpu/drm/drm_dp_mst_topology.c +++ b/drivers/gpu/drm/drm_dp_mst_topology.c @@ -1203,7 +1203,8 @@ static int drm_dp_mst_wait_tx_reply(struct drm_dp_mst_branch *mstb, } out: if (unlikely(ret == -EIO) && drm_debug_enabled(DRM_UT_DP)) { - struct drm_printer p = drm_debug_printer(DBG_PREFIX); + struct drm_printer p = drm_debug_category_printer(DRM_UT_DP, + DBG_PREFIX);

drm_dp_mst_dump_sideband_msg_tx(&p, txmsg); } @@ -2739,7 +2740,8 @@ static int process_single_tx_qlock(struct drm_dp_mst_topology_mgr *mgr,

ret = drm_dp_send_sideband_msg(mgr, up, chunk, idx); if (unlikely(ret) && drm_debug_enabled(DRM_UT_DP)) { - struct drm_printer p = drm_debug_printer(DBG_PREFIX); + struct drm_printer p = drm_debug_category_printer(DRM_UT_DP, + DBG_PREFIX);

drm_printf(&p, "sideband msg failed to send\n"); drm_dp_mst_dump_sideband_msg_tx(&p, txmsg); @@ -2783,7 +2785,8 @@ static void drm_dp_queue_down_tx(struct drm_dp_mst_topology_mgr *mgr, list_add_tail(&txmsg->next, &mgr->tx_msg_downq);

if (drm_debug_enabled(DRM_UT_DP)) { - struct drm_printer p = drm_debug_printer(DBG_PREFIX); + struct drm_printer p = drm_debug_category_printer(DRM_UT_DP, + DBG_PREFIX);

drm_dp_mst_dump_sideband_msg_tx(&p, txmsg); }

-- Sean Paul, Software Engineer, Google / Chromium OS

Sean Paul

9:05 p.m.

New subject: [PATCH v5 12/13] drm/i915: Use debug category printer for welcome message

From: Sean Paul seanpaul@chromium.org

The welcome printer is meant to be gated on DRM_UT_DRIVER, so use the debug category printer to avoid dumping the message in the wrong place.

Signed-off-by: Sean Paul seanpaul@chromium.org

Changes in v5: -Added to the set --- drivers/gpu/drm/i915/i915_drv.c | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/drivers/gpu/drm/i915/i915_drv.c b/drivers/gpu/drm/i915/i915_drv.c index 34ee12f3f02d..966212805ef7 100644 --- a/drivers/gpu/drm/i915/i915_drv.c +++ b/drivers/gpu/drm/i915/i915_drv.c @@ -876,7 +876,8 @@ static void i915_driver_unregister(struct drm_i915_private *dev_priv) static void i915_welcome_messages(struct drm_i915_private *dev_priv) { if (drm_debug_enabled(DRM_UT_DRIVER)) { - struct drm_printer p = drm_debug_printer("i915 device info:"); + struct drm_printer p = drm_debug_category_printer(DRM_UT_DRIVER, + "i915 device info:");

drm_printf(&p, "pciid=0x%04x rev=0x%02x platform=%s (subplatform=0x%x) gen=%i\n", INTEL_DEVID(dev_priv),

-- Sean Paul, Software Engineer, Google / Chromium OS

Sean Paul

9:05 p.m.

New subject: [PATCH v5 13/13] drm/print: Add tracefs support to the drm logging helpers

From: Sean Paul seanpaul@chromium.org

This patch adds a new module parameter called drm.trace which accepts the same mask as drm.debug. When a debug category is enabled, log messages will be put in a new tracefs instance called drm for consumption.

Using the new tracefs instance will allow distros to enable drm logging in production without impacting performance or spamming the system logs.

Cc: Daniel Vetter daniel.vetter@ffwll.ch Cc: David Airlie airlied@gmail.com Cc: Jani Nikula jani.nikula@linux.intel.com Cc: Joonas Lahtinen joonas.lahtinen@linux.intel.com Cc: Pekka Paalanen ppaalanen@gmail.com Cc: Rob Clark robdclark@gmail.com Cc: Steven Rostedt rostedt@goodmis.org Cc: Thomas Zimmermann tzimmermann@suse.de Cc: Ville Syrjälä ville.syrjala@linux.intel.com Cc: Chris Wilson chris@chris-wilson.co.uk Cc: Steven Rostedt rostedt@goodmis.org Signed-off-by: Sean Paul seanpaul@chromium.org Link: https://patchwork.freedesktop.org/patch/msgid/20191010204823.195540-1-sean@p... #v1 Link: https://lists.freedesktop.org/archives/dri-devel/2019-November/243230.html #v2 Link: https://patchwork.freedesktop.org/patch/msgid/20191212203301.142437-1-sean@p... #v3 Link: https://patchwork.freedesktop.org/patch/msgid/20200114172155.215463-1-sean@p... #v4

Changes in v5: -Re-write to use trace_array and the tracefs instance support --- Documentation/gpu/drm-uapi.rst | 6 + drivers/gpu/drm/drm_drv.c | 3 + drivers/gpu/drm/drm_print.c | 209 ++++++++++++++++++++++++++++----- include/drm/drm_print.h | 63 ++++++++-- 4 files changed, 241 insertions(+), 40 deletions(-)

diff --git a/Documentation/gpu/drm-uapi.rst b/Documentation/gpu/drm-uapi.rst index 56fec6ed1ad8..1c1c4d043f40 100644 --- a/Documentation/gpu/drm-uapi.rst +++ b/Documentation/gpu/drm-uapi.rst @@ -312,6 +312,12 @@ Debugfs Support .. kernel-doc:: drivers/gpu/drm/drm_debugfs.c :export:

+DRM Tracing +--------------- + +.. kernel-doc:: drivers/gpu/drm/drm_print.c + :doc: DRM Tracing + Sysfs Support =============

diff --git a/drivers/gpu/drm/drm_drv.c b/drivers/gpu/drm/drm_drv.c index bc38322f306e..88404af74c9b 100644 --- a/drivers/gpu/drm/drm_drv.c +++ b/drivers/gpu/drm/drm_drv.c @@ -1108,12 +1108,15 @@ static void drm_core_exit(void) drm_sysfs_destroy(); idr_destroy(&drm_minors_idr); drm_connector_ida_destroy(); + drm_trace_cleanup(); }

static int __init drm_core_init(void) { int ret;

+ drm_trace_init(); + drm_connector_ida_init(); idr_init(&drm_minors_idr);

diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 4d984a01b3a3..c4bef38921db 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -31,6 +31,7 @@ #include <linux/moduleparam.h> #include <linux/seq_file.h> #include <linux/slab.h> +#include <linux/trace.h>

#include <drm/drm.h> #include <drm/drm_drv.h> @@ -43,17 +44,34 @@ unsigned int __drm_debug_syslog; EXPORT_SYMBOL(__drm_debug_syslog);

-MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug category.\n" -"\t\tBit 0 (0x01) will enable CORE messages (drm core code)\n" -"\t\tBit 1 (0x02) will enable DRIVER messages (drm controller code)\n" -"\t\tBit 2 (0x04) will enable KMS messages (modesetting code)\n" -"\t\tBit 3 (0x08) will enable PRIME messages (prime code)\n" -"\t\tBit 4 (0x10) will enable ATOMIC messages (atomic code)\n" -"\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n" -"\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n" -"\t\tBit 8 (0x100) will enable DP messages (displayport code)"); +/* + * __drm_debug_trace: Enable debug output in drm tracing instance. + * Bitmask of DRM_UT_x. See include/drm/drm_print.h for details. + */ +unsigned int __drm_debug_trace; +EXPORT_SYMBOL(__drm_debug_trace); + +#define DEBUG_PARM_DESC(dst) \ +"Enable debug output to " dst ", where each bit enables a debug category.\n" \ +"\t\tBit 0 (0x01) will enable CORE messages (drm core code)\n" \ +"\t\tBit 1 (0x02) will enable DRIVER messages (drm controller code)\n" \ +"\t\tBit 2 (0x04) will enable KMS messages (modesetting code)\n" \ +"\t\tBit 3 (0x08) will enable PRIME messages (prime code)\n" \ +"\t\tBit 4 (0x10) will enable ATOMIC messages (atomic code)\n" \ +"\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n" \ +"\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n" \ +"\t\tBit 8 (0x100) will enable DP messages (displayport code)" + +MODULE_PARM_DESC(debug, DEBUG_PARM_DESC("syslog")); module_param_named(debug, __drm_debug_syslog, int, 0600);

+MODULE_PARM_DESC(trace, DEBUG_PARM_DESC("tracefs")); +module_param_named(trace, __drm_debug_trace, int, 0600); + +#ifdef CONFIG_TRACING +struct trace_array *trace_arr; +#endif + void __drm_puts_coredump(struct drm_printer *p, const char *str) { struct drm_print_iterator *iterator = p->arg; @@ -166,6 +184,20 @@ void __drm_printfn_debug_syslog(struct drm_printer *p, struct va_format *vaf) } EXPORT_SYMBOL(__drm_printfn_debug_syslog);

+void __drm_printfn_trace(struct drm_printer *p, struct va_format *vaf) +{ + drm_trace_printf("%s %pV", p->prefix, vaf); +} +EXPORT_SYMBOL(__drm_printfn_trace); + +void __drm_printfn_debug_syslog_and_trace(struct drm_printer *p, + struct va_format *vaf) +{ + pr_debug("%s %pV", p->prefix, vaf); + drm_trace_printf("%s %pV", p->prefix, vaf); +} +EXPORT_SYMBOL(__drm_printfn_debug_syslog_and_trace); + void __drm_printfn_err(struct drm_printer *p, struct va_format *vaf) { pr_err("*ERROR* %s %pV", p->prefix, vaf); @@ -246,6 +278,14 @@ void drm_dev_printk(const struct device *dev, const char *level, struct va_format vaf; va_list args;

+ va_start(args, format); + vaf.fmt = format; + vaf.va = &args; + drm_trace_printf("%s%s[" DRM_NAME ":%ps] %pV", + dev ? dev_name(dev) : "",dev ? " " : "", + __builtin_return_address(0), &vaf); + va_end(args); + va_start(args, format); vaf.fmt = format; vaf.va = &args; @@ -267,21 +307,30 @@ void drm_dev_dbg(const struct device *dev, enum drm_debug_category category, struct va_format vaf; va_list args;

- if (!drm_debug_enabled(category)) - return; + if (drm_debug_syslog_enabled(category)) { + va_start(args, format); + vaf.fmt = format; + vaf.va = &args;

- va_start(args, format); - vaf.fmt = format; - vaf.va = &args; + if (dev) + dev_printk(KERN_DEBUG, dev, "[" DRM_NAME ":%ps] %pV", + __builtin_return_address(0), &vaf); + else + printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV", + __builtin_return_address(0), &vaf);

- if (dev) - dev_printk(KERN_DEBUG, dev, "[" DRM_NAME ":%ps] %pV", - __builtin_return_address(0), &vaf); - else - printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV", - __builtin_return_address(0), &vaf); + va_end(args); + }

- va_end(args); + if (drm_debug_trace_enabled(category)) { + va_start(args, format); + vaf.fmt = format; + vaf.va = &args; + drm_trace_printf("%s%s[" DRM_NAME ":%ps] %pV", + dev ? dev_name(dev) : "", dev ? " " : "", + __builtin_return_address(0), &vaf); + va_end(args); + } } EXPORT_SYMBOL(drm_dev_dbg);

@@ -290,17 +339,25 @@ void __drm_dbg(enum drm_debug_category category, const char *format, ...) struct va_format vaf; va_list args;

- if (!drm_debug_enabled(category)) - return; + if (drm_debug_syslog_enabled(category)) { + va_start(args, format); + vaf.fmt = format; + vaf.va = &args;

- va_start(args, format); - vaf.fmt = format; - vaf.va = &args; + printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV", + __builtin_return_address(0), &vaf);

- printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV", - __builtin_return_address(0), &vaf); + va_end(args); + }

- va_end(args); + if (drm_debug_trace_enabled(category)) { + va_start(args, format); + vaf.fmt = format; + vaf.va = &args; + drm_trace_printf("[" DRM_NAME ":%ps] %pV", + __builtin_return_address(0), &vaf); + va_end(args); + } } EXPORT_SYMBOL(__drm_dbg);

@@ -347,3 +404,97 @@ void drm_print_regset32(struct drm_printer *p, struct debugfs_regset32 *regset) } } EXPORT_SYMBOL(drm_print_regset32); + + +/** + * DOC: DRM Tracing + * + * *tl;dr* DRM tracing is a lightweight alternative to traditional DRM debug + * logging. + * + * While DRM logging is quite convenient when reproducing a specific issue, it + * doesn't help when something goes wrong unexpectedly. There are a couple + * reasons why one does not want to enable DRM logging at all times: + * + * 1. We don't want to overwhelm syslog with drm spam, others have to use it too + * 2. Console logging is slow + * + * DRM tracing aims to solve both these problems. + * + * To use DRM tracing, set the drm.trace module parameter (via cmdline or sysfs) + * to a DRM debug category mask (this is a bitmask of &drm_debug_category + * values): + * :: + * + * eg: echo 0x106 > /sys/module/drm/parameters/trace + * + * Once active, all log messages in the specified categories will be written to + * the DRM trace. Once at capacity, the trace will overwrite old messages with + * new ones. At any point, one can read the trace file to extract the previous N + * DRM messages: + * :: + * + * eg: cat /sys/kernel/tracing/instances/drm/trace + * + * Considerations + * ************** + * The trace is subsystem wide, so if you have multiple devices active, they + * will be adding logs to the same trace. + * + * The contents of the DRM Trace are **not** considered UABI. **DO NOT depend on + * the values of these traces in your userspace.** These traces are intended for + * entertainment purposes only. The contents of these logs carry no warranty, + * expressed or implied. + */ + + +#ifdef CONFIG_TRACING + +/** + * drm_trace_init - initializes the drm trace array + * + * This function fetches (or creates) the drm trace array. This should be called + * once on drm subsystem creation and matched with drm_trace_cleanup(). + */ +void drm_trace_init() +{ + trace_arr = trace_array_get_by_name("drm"); + if (!trace_arr) + return; +} +EXPORT_SYMBOL(drm_trace_init); + +/** + * drm_trace_printf - adds an entry to the drm tracefs instance + * @format: printf format of the message to add to the trace + * + * This function adds a new entry in the drm tracefs instance + */ +void drm_trace_printf(const char *format, ...) +{ + struct va_format vaf; + va_list args; + + va_start(args, format); + vaf.fmt = format; + vaf.va = &args; + trace_array_printk(trace_arr, _THIS_IP_, "%pV", &vaf); + va_end(args); +} + +/** + * drm_trace_cleanup - destroys the drm trace array + * + * This function destroys the drm trace array created with drm_trace_init. This + * should be called once on drm subsystem close and matched with + * drm_trace_init(). + */ +void drm_trace_cleanup() +{ + if (trace_arr) { + trace_array_put(trace_arr); + trace_array_destroy(trace_arr); + } +} +EXPORT_SYMBOL(drm_trace_cleanup); +#endif \ No newline at end of file diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index 8987b98bbfda..284f7d325056 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -36,12 +36,13 @@

/* Do *not* use outside of drm_print.[ch]! */ extern unsigned int __drm_debug_syslog; +extern unsigned int __drm_debug_trace;

/** * DOC: print * * A simple wrapper for dev_printk(), seq_printf(), etc. Allows same - * debug code to be used for both debugfs and printk logging. + * debug code to be used for debugfs, printk and tracefs logging. * * For example:: * @@ -86,6 +87,9 @@ void __drm_printfn_seq_file(struct drm_printer *p, struct va_format *vaf); void __drm_puts_seq_file(struct drm_printer *p, const char *str); void __drm_printfn_info(struct drm_printer *p, struct va_format *vaf); void __drm_printfn_debug_syslog(struct drm_printer *p, struct va_format *vaf); +void __drm_printfn_trace(struct drm_printer *p, struct va_format *vaf); +void __drm_printfn_debug_syslog_and_trace(struct drm_printer *p, + struct va_format *vaf); void __drm_printfn_err(struct drm_printer *p, struct va_format *vaf); void __drm_printfn_noop(struct drm_printer *p, struct va_format *vaf);

@@ -219,7 +223,8 @@ static inline struct drm_printer drm_info_printer(struct device *dev) }

/** - * drm_debug_printer - construct a &drm_printer that outputs to pr_debug() + * drm_debug_printer - construct a &drm_printer that outputs to pr_debug() and + * drm tracefs * @prefix: debug output prefix * * RETURNS: @@ -228,7 +233,7 @@ static inline struct drm_printer drm_info_printer(struct device *dev) static inline struct drm_printer drm_debug_printer(const char *prefix) { struct drm_printer p = { - .printfn = __drm_printfn_debug_syslog, + .printfn = __drm_printfn_debug_syslog_and_trace, .prefix = prefix }; return p; @@ -254,14 +259,14 @@ static inline struct drm_printer drm_err_printer(const char *prefix) * enum drm_debug_category - The DRM debug categories * * Each of the DRM debug logging macros use a specific category, and the logging - * is filtered by the drm.debug module parameter. This enum specifies the values - * for the interface. + * is filtered by the drm.debug and drm.trace module parameters. This enum + * specifies the values for the interface. * * Each DRM_DEBUG_<CATEGORY> macro logs to DRM_UT_<CATEGORY> category, except * DRM_DEBUG() logs to DRM_UT_CORE. * - * Enabling verbose debug messages is done through the drm.debug parameter, each - * category being enabled by a bit: + * Enabling verbose debug messages is done through the drm.debug and drm.trace + * parameters, each category being enabled by a bit: * * - drm.debug=0x1 will enable CORE messages * - drm.debug=0x2 will enable DRIVER messages @@ -270,10 +275,14 @@ static inline struct drm_printer drm_err_printer(const char *prefix) * - drm.debug=0x1ff will enable all messages * * An interesting feature is that it's possible to enable verbose logging at - * run-time by echoing the debug value in its sysfs node:: + * run-time by echoing the debug category value in its sysfs node:: * + * # For syslog logging: * # echo 0xf > /sys/module/drm/parameters/debug * + * # For tracefs logging: + * # echo 0xf > /sys/module/drm/parameters/trace + * */ enum drm_debug_category { /** @@ -325,14 +334,20 @@ static inline bool drm_debug_syslog_enabled(enum drm_debug_category category) return unlikely(__drm_debug_syslog & category); }

+static inline bool drm_debug_trace_enabled(enum drm_debug_category category) +{ + return unlikely(__drm_debug_trace & category); +} + static inline bool drm_debug_enabled(enum drm_debug_category category) { - return drm_debug_syslog_enabled(category); + return drm_debug_syslog_enabled(category) || + drm_debug_trace_enabled(category); }

/** * drm_debug_category_printer - construct a &drm_printer that outputs to - * pr_debug() if enabled for the given category. + * pr_debug() and/or the drm tracefs instance if enabled for the given category. * @category: the DRM_UT_* message category this message belongs to * @prefix: trace output prefix * @@ -347,8 +362,13 @@ drm_debug_category_printer(enum drm_debug_category category, .prefix = prefix };

- if (drm_debug_syslog_enabled(category)) { + if (drm_debug_syslog_enabled(category) && + drm_debug_trace_enabled(category)) { + p.printfn = __drm_printfn_debug_syslog_and_trace; + } else if (drm_debug_syslog_enabled(category)) { p.printfn = __drm_printfn_debug_syslog; + } else if (drm_debug_trace_enabled(category)) { + p.printfn = __drm_printfn_trace; } else { WARN(1, "Debug category %d is inactive.", category); p.printfn = __drm_printfn_noop; @@ -357,6 +377,27 @@ drm_debug_category_printer(enum drm_debug_category category, return p; }

+ +#ifdef CONFIG_TRACING +void drm_trace_init(void); +__printf(1, 2) +void drm_trace_printf(const char *format, ...); +void drm_trace_cleanup(void); +#else +static inline void drm_trace_init(void) +{ +} + +__printf(1, 2) +static inline void drm_trace_printf(const char *format, ...) +{ +} + +static inline void drm_trace_cleanup(void) +{ +} +#endif + /* * struct device based logging *

-- Sean Paul, Software Engineer, Google / Chromium OS

kernel test robot

11:47 p.m.

New subject: [PATCH v5 13/13] drm/print: Add tracefs support to the drm logging helpers

Hi Sean,

I love your patch! Perhaps something to improve:

[auto build test WARNING on drm-intel/for-linux-next] [also build test WARNING on drm-exynos/exynos-drm-next tegra-drm/drm/tegra/for-next drm-tip/drm-tip linus/master v5.7] [cannot apply to drm/drm-next] [if your patch is applied to the wrong git tree, please drop us a note to help improve the system. BTW, we also suggest to use '--base' option to specify the base tree in git format-patch, please see https://stackoverflow.com/a/37406982]

url: https://github.com/0day-ci/linux/commits/Sean-Paul/drm-trace-Mirror-DRM-debu... base: git://anongit.freedesktop.org/drm-intel for-linux-next config: riscv-allyesconfig (attached as .config) compiler: riscv64-linux-gcc (GCC) 9.3.0 reproduce (this is a W=1 build): wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross chmod +x ~/bin/make.cross # save the attached .config to linux build tree COMPILER_INSTALL_PATH=$HOME/0day COMPILER=gcc-9.3.0 make.cross ARCH=riscv

If you fix the issue, kindly add following tag as appropriate Reported-by: kernel test robot lkp@intel.com

All warnings (new ones prefixed by >>, old ones prefixed by <<):

drivers/gpu/drm/drm_print.c: In function 'drm_trace_init':

...

...
drivers/gpu/drm/drm_print.c:459:6: warning: old-style function definition [-Wold-style-definition]

459 | void drm_trace_init() | ^~~~~~~~~~~~~~ drivers/gpu/drm/drm_print.c: In function 'drm_trace_cleanup': drivers/gpu/drm/drm_print.c:492:6: warning: old-style function definition [-Wold-style-definition] 492 | void drm_trace_cleanup() | ^~~~~~~~~~~~~~~~~

vim +459 drivers/gpu/drm/drm_print.c

452 453 /** 454 * drm_trace_init - initializes the drm trace array 455 * 456 * This function fetches (or creates) the drm trace array. This should be called 457 * once on drm subsystem creation and matched with drm_trace_cleanup(). 458 */

...

459 void drm_trace_init()

460 { 461 trace_arr = trace_array_get_by_name("drm"); 462 if (!trace_arr) 463 return; 464 } 465 EXPORT_SYMBOL(drm_trace_init); 466

--- 0-DAY CI Kernel Test Service, Intel Corporation https://lists.01.org/hyperkitty/list/kbuild-all@lists.01.org

kernel test robot

9 Jun 9 Jun

1:45 a.m.

New subject: [PATCH v5 13/13] drm/print: Add tracefs support to the drm logging helpers

Hi Sean,

I love your patch! Perhaps something to improve:

[auto build test WARNING on drm-intel/for-linux-next] [also build test WARNING on drm-exynos/exynos-drm-next tegra-drm/drm/tegra/for-next drm-tip/drm-tip linus/master v5.7 next-20200608] [cannot apply to drm/drm-next] [if your patch is applied to the wrong git tree, please drop us a note to help improve the system. BTW, we also suggest to use '--base' option to specify the base tree in git format-patch, please see https://stackoverflow.com/a/37406982]

url: https://github.com/0day-ci/linux/commits/Sean-Paul/drm-trace-Mirror-DRM-debu... base: git://anongit.freedesktop.org/drm-intel for-linux-next config: x86_64-randconfig-s021-20200607 (attached as .config) compiler: gcc-9 (Debian 9.3.0-13) 9.3.0 reproduce: # apt-get install sparse # sparse version: v0.6.1-247-gcadbd124-dirty # save the attached .config to linux build tree make W=1 C=1 ARCH=x86_64 CF='-fdiagnostic-prefix -D__CHECK_ENDIAN__'

If you fix the issue, kindly add following tag as appropriate Reported-by: kernel test robot lkp@intel.com

sparse warnings: (new ones prefixed by >>)

...

...
drivers/gpu/drm/drm_print.c:459:21: sparse: sparse: non-ANSI function declaration of function 'drm_trace_init' drivers/gpu/drm/drm_print.c:492:24: sparse: sparse: non-ANSI function declaration of function 'drm_trace_cleanup'

Please review and possibly fold the followup patch.

vim +/drm_trace_init +459 drivers/gpu/drm/drm_print.c

...

459 void drm_trace_init()

460 { 461 trace_arr = trace_array_get_by_name("drm"); 462 if (!trace_arr) 463 return; 464 } 465 EXPORT_SYMBOL(drm_trace_init); 466 467 /** 468 * drm_trace_printf - adds an entry to the drm tracefs instance 469 * @format: printf format of the message to add to the trace 470 * 471 * This function adds a new entry in the drm tracefs instance 472 */ 473 void drm_trace_printf(const char *format, ...) 474 { 475 struct va_format vaf; 476 va_list args; 477 478 va_start(args, format); 479 vaf.fmt = format; 480 vaf.va = &args; 481 trace_array_printk(trace_arr, _THIS_IP_, "%pV", &vaf); 482 va_end(args); 483 } 484 485 /** 486 * drm_trace_cleanup - destroys the drm trace array 487 * 488 * This function destroys the drm trace array created with drm_trace_init. This 489 * should be called once on drm subsystem close and matched with 490 * drm_trace_init(). 491 */

...

492 void drm_trace_cleanup()

--- 0-DAY CI Kernel Test Service, Intel Corporation https://lists.01.org/hyperkitty/list/kbuild-all@lists.01.org

Sean Paul

3:49 p.m.

New subject: [PATCH v6 13/13] drm/print: Add tracefs support to the drm logging helpers

From: Sean Paul seanpaul@chromium.org

Using the new tracefs instance will allow distros to enable drm logging in production without impacting performance or spamming the system logs.

Changes in v5: -Re-write to use trace_array and the tracefs instance support

Changes in v6: -Fix old-style function definition warnings Reported-by: kernel test robot lkp@intel.com --- Documentation/gpu/drm-uapi.rst | 6 + drivers/gpu/drm/drm_drv.c | 3 + drivers/gpu/drm/drm_print.c | 209 ++++++++++++++++++++++++++++----- include/drm/drm_print.h | 63 ++++++++-- 4 files changed, 241 insertions(+), 40 deletions(-)

+DRM Tracing +--------------- + +.. kernel-doc:: drivers/gpu/drm/drm_print.c + :doc: DRM Tracing + Sysfs Support =============

static int __init drm_core_init(void) { int ret;

+ drm_trace_init(); + drm_connector_ida_init(); idr_init(&drm_minors_idr);

diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 4d984a01b3a3..18dfbd43c23b 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -31,6 +31,7 @@ #include <linux/moduleparam.h> #include <linux/seq_file.h> #include <linux/slab.h> +#include <linux/trace.h>

#include <drm/drm.h> #include <drm/drm_drv.h> @@ -43,17 +44,34 @@ unsigned int __drm_debug_syslog; EXPORT_SYMBOL(__drm_debug_syslog);

- if (!drm_debug_enabled(category)) - return; + if (drm_debug_syslog_enabled(category)) { + va_start(args, format); + vaf.fmt = format; + vaf.va = &args;

@@ -290,17 +339,25 @@ void __drm_dbg(enum drm_debug_category category, const char *format, ...) struct va_format vaf; va_list args;

- if (!drm_debug_enabled(category)) - return; + if (drm_debug_syslog_enabled(category)) { + va_start(args, format); + vaf.fmt = format; + vaf.va = &args;

- va_start(args, format); - vaf.fmt = format; - vaf.va = &args; + printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV", + __builtin_return_address(0), &vaf);

- printk(KERN_DEBUG "[" DRM_NAME ":%ps] %pV", - __builtin_return_address(0), &vaf); + va_end(args); + }

@@ -347,3 +404,97 @@ void drm_print_regset32(struct drm_printer *p, struct debugfs_regset32 *regset) } } EXPORT_SYMBOL(drm_print_regset32); + + +/** + * DOC: DRM Tracing + * + * *tl;dr* DRM tracing is a lightweight alternative to traditional DRM debug + * logging. + * + * While DRM logging is quite convenient when reproducing a specific issue, it + * doesn't help when something goes wrong unexpectedly. There are a couple + * reasons why one does not want to enable DRM logging at all times: + * + * 1. We don't want to overwhelm syslog with drm spam, others have to use it too + * 2. Console logging is slow + * + * DRM tracing aims to solve both these problems. + * + * To use DRM tracing, set the drm.trace module parameter (via cmdline or sysfs) + * to a DRM debug category mask (this is a bitmask of &drm_debug_category + * values): + * :: + * + * eg: echo 0x106 > /sys/module/drm/parameters/trace + * + * Once active, all log messages in the specified categories will be written to + * the DRM trace. Once at capacity, the trace will overwrite old messages with + * new ones. At any point, one can read the trace file to extract the previous N + * DRM messages: + * :: + * + * eg: cat /sys/kernel/tracing/instances/drm/trace + * + * Considerations + * ************** + * The trace is subsystem wide, so if you have multiple devices active, they + * will be adding logs to the same trace. + * + * The contents of the DRM Trace are **not** considered UABI. **DO NOT depend on + * the values of these traces in your userspace.** These traces are intended for + * entertainment purposes only. The contents of these logs carry no warranty, + * expressed or implied. + */ + + +#ifdef CONFIG_TRACING + +/** + * drm_trace_init - initializes the drm trace array + * + * This function fetches (or creates) the drm trace array. This should be called + * once on drm subsystem creation and matched with drm_trace_cleanup(). + */ +void drm_trace_init(void) +{ + trace_arr = trace_array_get_by_name("drm"); + if (!trace_arr) + return; +} +EXPORT_SYMBOL(drm_trace_init); + +/** + * drm_trace_printf - adds an entry to the drm tracefs instance + * @format: printf format of the message to add to the trace + * + * This function adds a new entry in the drm tracefs instance + */ +void drm_trace_printf(const char *format, ...) +{ + struct va_format vaf; + va_list args; + + va_start(args, format); + vaf.fmt = format; + vaf.va = &args; + trace_array_printk(trace_arr, _THIS_IP_, "%pV", &vaf); + va_end(args); +} + +/** + * drm_trace_cleanup - destroys the drm trace array + * + * This function destroys the drm trace array created with drm_trace_init. This + * should be called once on drm subsystem close and matched with + * drm_trace_init(). + */ +void drm_trace_cleanup(void) +{ + if (trace_arr) { + trace_array_put(trace_arr); + trace_array_destroy(trace_arr); + } +} +EXPORT_SYMBOL(drm_trace_cleanup); +#endif diff --git a/include/drm/drm_print.h b/include/drm/drm_print.h index 8987b98bbfda..284f7d325056 100644 --- a/include/drm/drm_print.h +++ b/include/drm/drm_print.h @@ -36,12 +36,13 @@

/* Do *not* use outside of drm_print.[ch]! */ extern unsigned int __drm_debug_syslog; +extern unsigned int __drm_debug_trace;

@@ -219,7 +223,8 @@ static inline struct drm_printer drm_info_printer(struct device *dev) }

-- Sean Paul, Software Engineer, Google / Chromium OS

Steven Rostedt

10 Jun 10 Jun

3:01 p.m.

New subject: [PATCH v6 13/13] drm/print: Add tracefs support to the drm logging helpers

On Tue, 9 Jun 2020 11:49:19 -0400 Sean Paul sean@poorly.run wrote:

...

+/**

drm_trace_printf - adds an entry to the drm tracefs instance

@format: printf format of the message to add to the trace

This function adds a new entry in the drm tracefs instance

*/

+void drm_trace_printf(const char *format, ...) +{

struct va_format vaf;

va_list args;

va_start(args, format);

vaf.fmt = format;

vaf.va = &args;

trace_array_printk(trace_arr, _THIS_IP_, "%pV", &vaf);

va_end(args);

+}

The only issue I have with this patch is the above. I really dislike the use of trace_array_print(), as that is made to be for debugging and not something that should be in a production kernel.

Ideally, every instance should just pass the data it wants to record, and you add it to a trace event. There's already a drm trace subsystem, how would this be different. Perhaps create a drm_log subsystem, and you only need to have your instance enable it?

I guess I'm still confused to why this is needed over just having trace events? What's special about this case?

-- Steve

Sean Paul

3:29 p.m.

New subject: [PATCH v6 13/13] drm/print: Add tracefs support to the drm logging helpers

On Wed, Jun 10, 2020 at 11:01 AM Steven Rostedt rostedt@goodmis.org wrote:

...

On Tue, 9 Jun 2020 11:49:19 -0400 Sean Paul sean@poorly.run wrote:

...
+/**

drm_trace_printf - adds an entry to the drm tracefs instance

@format: printf format of the message to add to the trace

This function adds a new entry in the drm tracefs instance

*/

+void drm_trace_printf(const char *format, ...) +{
struct va_format vaf;
va_list args;
va_start(args, format);
vaf.fmt = format;
vaf.va = &args;
trace_array_printk(trace_arr, _THIS_IP_, "%pV", &vaf);
va_end(args);
+}
The only issue I have with this patch is the above. I really dislike the use of trace_array_print(), as that is made to be for debugging and not something that should be in a production kernel.

Ideally, every instance should just pass the data it wants to record, and you add it to a trace event. There's already a drm trace subsystem, how would this be different. Perhaps create a drm_log subsystem, and you only need to have your instance enable it?

I guess I'm still confused to why this is needed over just having trace events? What's special about this case?

Hi Steve, In v2 I had added trace events throughout drm in this manner. See https://lists.freedesktop.org/archives/dri-devel/2019-November/243318.html

The feedback I received was that exposing the events in such a structured way would bind us to the trace formats and make things more difficult moving forward.

Aside from the UAPI concerns, wearing my ChromeOS hat (with full knowledge that most upstream folks won't care about this), this solution also misses on making problems easier to diagnose from logs/user feedback. It requires that driver developers add tracing beside their logging, and makes backporting upstream code even harder than it is right now. If we can intercept the existing and new logging at the source, it's much easier to ensure the flight recorder is accurate. We've been shipping this (v4) in CrOS for ~months now and it's been invaluable. With this experience in mind, I'd be really hesitant to change course.

Sean

...

-- Steve

kernel test robot

9 Jun 9 Jun

1:45 a.m.

New subject: [RFC PATCH] drm/print: trace_arr can be static

Signed-off-by: kernel test robot lkp@intel.com --- drm_print.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index c4bef38921db1..a50d0b24c911f 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -69,7 +69,7 @@ MODULE_PARM_DESC(trace, DEBUG_PARM_DESC("tracefs")); module_param_named(trace, __drm_debug_trace, int, 0600);

#ifdef CONFIG_TRACING -struct trace_array *trace_arr; +static struct trace_array *trace_arr; #endif

void __drm_puts_coredump(struct drm_printer *p, const char *str)

Pekka Paalanen

10 Jun 10 Jun

7:57 a.m.

New subject: [PATCH v5 13/13] drm/print: Add tracefs support to the drm logging helpers

On Mon, 8 Jun 2020 17:05:03 -0400 Sean Paul sean@poorly.run wrote:

...

From: Sean Paul seanpaul@chromium.org

This patch adds a new module parameter called drm.trace which accepts the same mask as drm.debug. When a debug category is enabled, log messages will be put in a new tracefs instance called drm for consumption.

Using the new tracefs instance will allow distros to enable drm logging in production without impacting performance or spamming the system logs.

Cc: Daniel Vetter daniel.vetter@ffwll.ch Cc: David Airlie airlied@gmail.com Cc: Jani Nikula jani.nikula@linux.intel.com Cc: Joonas Lahtinen joonas.lahtinen@linux.intel.com Cc: Pekka Paalanen ppaalanen@gmail.com Cc: Rob Clark robdclark@gmail.com Cc: Steven Rostedt rostedt@goodmis.org Cc: Thomas Zimmermann tzimmermann@suse.de Cc: Ville Syrjälä ville.syrjala@linux.intel.com Cc: Chris Wilson chris@chris-wilson.co.uk Cc: Steven Rostedt rostedt@goodmis.org Signed-off-by: Sean Paul seanpaul@chromium.org Link: https://patchwork.freedesktop.org/patch/msgid/20191010204823.195540-1-sean@p... #v1 Link: https://lists.freedesktop.org/archives/dri-devel/2019-November/243230.html #v2 Link: https://patchwork.freedesktop.org/patch/msgid/20191212203301.142437-1-sean@p... #v3 Link: https://patchwork.freedesktop.org/patch/msgid/20200114172155.215463-1-sean@p... #v4

Changes in v5:

-Re-write to use trace_array and the tracefs instance support

Documentation/gpu/drm-uapi.rst | 6 + drivers/gpu/drm/drm_drv.c | 3 + drivers/gpu/drm/drm_print.c | 209 ++++++++++++++++++++++++++++----- include/drm/drm_print.h | 63 ++++++++-- 4 files changed, 241 insertions(+), 40 deletions(-)

diff --git a/Documentation/gpu/drm-uapi.rst b/Documentation/gpu/drm-uapi.rst index 56fec6ed1ad8..1c1c4d043f40 100644 --- a/Documentation/gpu/drm-uapi.rst +++ b/Documentation/gpu/drm-uapi.rst @@ -312,6 +312,12 @@ Debugfs Support .. kernel-doc:: drivers/gpu/drm/drm_debugfs.c :export:

+DRM Tracing +---------------

+.. kernel-doc:: drivers/gpu/drm/drm_print.c

:doc: DRM Tracing

Sysfs Support

diff --git a/drivers/gpu/drm/drm_drv.c b/drivers/gpu/drm/drm_drv.c index bc38322f306e..88404af74c9b 100644 --- a/drivers/gpu/drm/drm_drv.c +++ b/drivers/gpu/drm/drm_drv.c @@ -1108,12 +1108,15 @@ static void drm_core_exit(void) drm_sysfs_destroy(); idr_destroy(&drm_minors_idr); drm_connector_ida_destroy();

drm_trace_cleanup();

}

static int __init drm_core_init(void) { int ret;

drm_trace_init();

drm_connector_ida_init(); idr_init(&drm_minors_idr);

diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 4d984a01b3a3..c4bef38921db 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -31,6 +31,7 @@ #include <linux/moduleparam.h> #include <linux/seq_file.h> #include <linux/slab.h> +#include <linux/trace.h>

#include <drm/drm.h> #include <drm/drm_drv.h> @@ -43,17 +44,34 @@ unsigned int __drm_debug_syslog; EXPORT_SYMBOL(__drm_debug_syslog);

-MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug category.\n" -"\t\tBit 0 (0x01) will enable CORE messages (drm core code)\n" -"\t\tBit 1 (0x02) will enable DRIVER messages (drm controller code)\n" -"\t\tBit 2 (0x04) will enable KMS messages (modesetting code)\n" -"\t\tBit 3 (0x08) will enable PRIME messages (prime code)\n" -"\t\tBit 4 (0x10) will enable ATOMIC messages (atomic code)\n" -"\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n" -"\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n" -"\t\tBit 8 (0x100) will enable DP messages (displayport code)"); +/*

__drm_debug_trace: Enable debug output in drm tracing instance.

Bitmask of DRM_UT_x. See include/drm/drm_print.h for details.

*/

+unsigned int __drm_debug_trace; +EXPORT_SYMBOL(__drm_debug_trace);

Hi!

Might distributions perhaps want to set a default value for this via Kconfig? Or could setting it via sysfs happen early enough to diagnose e.g. Plymouth problems?

Or maybe there is nothing to see from early boot?

The general usefulness of this feature depends on whether people actually run with it enabled.

...

+#define DEBUG_PARM_DESC(dst) \ +"Enable debug output to " dst ", where each bit enables a debug category.\n" \ +"\t\tBit 0 (0x01) will enable CORE messages (drm core code)\n" \ +"\t\tBit 1 (0x02) will enable DRIVER messages (drm controller code)\n" \ +"\t\tBit 2 (0x04) will enable KMS messages (modesetting code)\n" \ +"\t\tBit 3 (0x08) will enable PRIME messages (prime code)\n" \ +"\t\tBit 4 (0x10) will enable ATOMIC messages (atomic code)\n" \ +"\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n" \ +"\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n" \ +"\t\tBit 8 (0x100) will enable DP messages (displayport code)"

+MODULE_PARM_DESC(debug, DEBUG_PARM_DESC("syslog")); module_param_named(debug, __drm_debug_syslog, int, 0600);

+MODULE_PARM_DESC(trace, DEBUG_PARM_DESC("tracefs")); +module_param_named(trace, __drm_debug_trace, int, 0600);

...

+/**

DOC: DRM Tracing

*tl;dr* DRM tracing is a lightweight alternative to traditional DRM debug

logging.

While DRM logging is quite convenient when reproducing a specific issue, it

doesn't help when something goes wrong unexpectedly. There are a couple

reasons why one does not want to enable DRM logging at all times:

We don't want to overwhelm syslog with drm spam, others have to use it too

Console logging is slow

DRM tracing aims to solve both these problems.

To use DRM tracing, set the drm.trace module parameter (via cmdline or sysfs)

to a DRM debug category mask (this is a bitmask of &drm_debug_category

values):

::

eg: echo 0x106 > /sys/module/drm/parameters/trace

Once active, all log messages in the specified categories will be written to

the DRM trace. Once at capacity, the trace will overwrite old messages with

new ones. At any point, one can read the trace file to extract the previous N

DRM messages:

::

eg: cat /sys/kernel/tracing/instances/drm/trace

Considerations

The trace is subsystem wide, so if you have multiple devices active, they

will be adding logs to the same trace.

The contents of the DRM Trace are **not** considered UABI. **DO NOT depend on

the values of these traces in your userspace.** These traces are intended for

entertainment purposes only. The contents of these logs carry no warranty,

expressed or implied.

*/

Sounds good to me! This part is: Acked-by: Pekka Paalanen pekka.paalanen@collabora.com

Thanks, pq

Sean Paul

1:29 p.m.

New subject: [PATCH v5 13/13] drm/print: Add tracefs support to the drm logging helpers

On Wed, Jun 10, 2020 at 3:57 AM Pekka Paalanen ppaalanen@gmail.com wrote:

...

On Mon, 8 Jun 2020 17:05:03 -0400 Sean Paul sean@poorly.run wrote:

...
From: Sean Paul seanpaul@chromium.org

This patch adds a new module parameter called drm.trace which accepts the same mask as drm.debug. When a debug category is enabled, log messages will be put in a new tracefs instance called drm for consumption.

Using the new tracefs instance will allow distros to enable drm logging in production without impacting performance or spamming the system logs.

Cc: Daniel Vetter daniel.vetter@ffwll.ch Cc: David Airlie airlied@gmail.com Cc: Jani Nikula jani.nikula@linux.intel.com Cc: Joonas Lahtinen joonas.lahtinen@linux.intel.com Cc: Pekka Paalanen ppaalanen@gmail.com Cc: Rob Clark robdclark@gmail.com Cc: Steven Rostedt rostedt@goodmis.org Cc: Thomas Zimmermann tzimmermann@suse.de Cc: Ville Syrjälä ville.syrjala@linux.intel.com Cc: Chris Wilson chris@chris-wilson.co.uk Cc: Steven Rostedt rostedt@goodmis.org Signed-off-by: Sean Paul seanpaul@chromium.org Link: https://patchwork.freedesktop.org/patch/msgid/20191010204823.195540-1-sean@p... #v1 Link: https://lists.freedesktop.org/archives/dri-devel/2019-November/243230.html #v2 Link: https://patchwork.freedesktop.org/patch/msgid/20191212203301.142437-1-sean@p... #v3 Link: https://patchwork.freedesktop.org/patch/msgid/20200114172155.215463-1-sean@p... #v4

Changes in v5:

-Re-write to use trace_array and the tracefs instance support

Documentation/gpu/drm-uapi.rst | 6 + drivers/gpu/drm/drm_drv.c | 3 + drivers/gpu/drm/drm_print.c | 209 ++++++++++++++++++++++++++++----- include/drm/drm_print.h | 63 ++++++++-- 4 files changed, 241 insertions(+), 40 deletions(-)

diff --git a/Documentation/gpu/drm-uapi.rst b/Documentation/gpu/drm-uapi.rst index 56fec6ed1ad8..1c1c4d043f40 100644 --- a/Documentation/gpu/drm-uapi.rst +++ b/Documentation/gpu/drm-uapi.rst @@ -312,6 +312,12 @@ Debugfs Support .. kernel-doc:: drivers/gpu/drm/drm_debugfs.c :export:

+DRM Tracing +---------------

+.. kernel-doc:: drivers/gpu/drm/drm_print.c

:doc: DRM Tracing

Sysfs Support

diff --git a/drivers/gpu/drm/drm_drv.c b/drivers/gpu/drm/drm_drv.c index bc38322f306e..88404af74c9b 100644 --- a/drivers/gpu/drm/drm_drv.c +++ b/drivers/gpu/drm/drm_drv.c @@ -1108,12 +1108,15 @@ static void drm_core_exit(void) drm_sysfs_destroy(); idr_destroy(&drm_minors_idr); drm_connector_ida_destroy();
drm_trace_cleanup();
}

static int __init drm_core_init(void) { int ret;
drm_trace_init();
drm_connector_ida_init();
idr_init(&drm_minors_idr);
diff --git a/drivers/gpu/drm/drm_print.c b/drivers/gpu/drm/drm_print.c index 4d984a01b3a3..c4bef38921db 100644 --- a/drivers/gpu/drm/drm_print.c +++ b/drivers/gpu/drm/drm_print.c @@ -31,6 +31,7 @@ #include <linux/moduleparam.h> #include <linux/seq_file.h> #include <linux/slab.h> +#include <linux/trace.h>

#include <drm/drm.h> #include <drm/drm_drv.h> @@ -43,17 +44,34 @@ unsigned int __drm_debug_syslog; EXPORT_SYMBOL(__drm_debug_syslog);

-MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug category.\n" -"\t\tBit 0 (0x01) will enable CORE messages (drm core code)\n" -"\t\tBit 1 (0x02) will enable DRIVER messages (drm controller code)\n" -"\t\tBit 2 (0x04) will enable KMS messages (modesetting code)\n" -"\t\tBit 3 (0x08) will enable PRIME messages (prime code)\n" -"\t\tBit 4 (0x10) will enable ATOMIC messages (atomic code)\n" -"\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n" -"\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n" -"\t\tBit 8 (0x100) will enable DP messages (displayport code)"); +/*

__drm_debug_trace: Enable debug output in drm tracing instance.

Bitmask of DRM_UT_x. See include/drm/drm_print.h for details.

*/

+unsigned int __drm_debug_trace; +EXPORT_SYMBOL(__drm_debug_trace);
Hi!

Hi Pekka, Thanks again for the feedback, I'm happy that we seem to be converging!

...

Might distributions perhaps want to set a default value for this via Kconfig? Or could setting it via sysfs happen early enough to diagnose e.g. Plymouth problems?

Or maybe there is nothing to see from early boot?

The general usefulness of this feature depends on whether people actually run with it enabled.

I had assumed that the cmdline argument would be sufficient for distros, is Kconfig preferable here? The module parameter has the advantage of being runtime configurable and is more in line with drm.debug. We can do either in CrOS, so I'm happy to go with crowd consensus.

Sean

...

...

+#define DEBUG_PARM_DESC(dst) \ +"Enable debug output to " dst ", where each bit enables a debug category.\n" \ +"\t\tBit 0 (0x01) will enable CORE messages (drm core code)\n" \ +"\t\tBit 1 (0x02) will enable DRIVER messages (drm controller code)\n" \ +"\t\tBit 2 (0x04) will enable KMS messages (modesetting code)\n" \ +"\t\tBit 3 (0x08) will enable PRIME messages (prime code)\n" \ +"\t\tBit 4 (0x10) will enable ATOMIC messages (atomic code)\n" \ +"\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n" \ +"\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n" \ +"\t\tBit 8 (0x100) will enable DP messages (displayport code)"

+MODULE_PARM_DESC(debug, DEBUG_PARM_DESC("syslog")); module_param_named(debug, __drm_debug_syslog, int, 0600);

+MODULE_PARM_DESC(trace, DEBUG_PARM_DESC("tracefs")); +module_param_named(trace, __drm_debug_trace, int, 0600);

...

...

+/**

DOC: DRM Tracing

*tl;dr* DRM tracing is a lightweight alternative to traditional DRM debug

logging.

While DRM logging is quite convenient when reproducing a specific issue, it

doesn't help when something goes wrong unexpectedly. There are a couple

reasons why one does not want to enable DRM logging at all times:

We don't want to overwhelm syslog with drm spam, others have to use it too

Console logging is slow

DRM tracing aims to solve both these problems.

To use DRM tracing, set the drm.trace module parameter (via cmdline or sysfs)

to a DRM debug category mask (this is a bitmask of &drm_debug_category

values):

::

eg: echo 0x106 > /sys/module/drm/parameters/trace

Once active, all log messages in the specified categories will be written to

the DRM trace. Once at capacity, the trace will overwrite old messages with

new ones. At any point, one can read the trace file to extract the previous N

DRM messages:

::

eg: cat /sys/kernel/tracing/instances/drm/trace

Considerations

The trace is subsystem wide, so if you have multiple devices active, they

will be adding logs to the same trace.

The contents of the DRM Trace are **not** considered UABI. **DO NOT depend on

the values of these traces in your userspace.** These traces are intended for

entertainment purposes only. The contents of these logs carry no warranty,

expressed or implied.

*/

Sounds good to me! This part is: Acked-by: Pekka Paalanen pekka.paalanen@collabora.com

Thanks, pq

Pekka Paalanen

2:09 p.m.

New subject: [PATCH v5 13/13] drm/print: Add tracefs support to the drm logging helpers

On Wed, 10 Jun 2020 09:29:37 -0400 Sean Paul sean@poorly.run wrote:

...

On Wed, Jun 10, 2020 at 3:57 AM Pekka Paalanen ppaalanen@gmail.com wrote:

...
On Mon, 8 Jun 2020 17:05:03 -0400 Sean Paul sean@poorly.run wrote:

...
From: Sean Paul seanpaul@chromium.org

This patch adds a new module parameter called drm.trace which accepts the same mask as drm.debug. When a debug category is enabled, log messages will be put in a new tracefs instance called drm for consumption.

Using the new tracefs instance will allow distros to enable drm logging in production without impacting performance or spamming the system logs.

Cc: Daniel Vetter daniel.vetter@ffwll.ch Cc: David Airlie airlied@gmail.com Cc: Jani Nikula jani.nikula@linux.intel.com Cc: Joonas Lahtinen joonas.lahtinen@linux.intel.com Cc: Pekka Paalanen ppaalanen@gmail.com Cc: Rob Clark robdclark@gmail.com Cc: Steven Rostedt rostedt@goodmis.org Cc: Thomas Zimmermann tzimmermann@suse.de Cc: Ville Syrjälä ville.syrjala@linux.intel.com Cc: Chris Wilson chris@chris-wilson.co.uk Cc: Steven Rostedt rostedt@goodmis.org Signed-off-by: Sean Paul seanpaul@chromium.org Link: https://patchwork.freedesktop.org/patch/msgid/20191010204823.195540-1-sean@p... #v1 Link: https://lists.freedesktop.org/archives/dri-devel/2019-November/243230.html #v2 Link: https://patchwork.freedesktop.org/patch/msgid/20191212203301.142437-1-sean@p... #v3 Link: https://patchwork.freedesktop.org/patch/msgid/20200114172155.215463-1-sean@p... #v4

Changes in v5:

-Re-write to use trace_array and the tracefs instance support

Documentation/gpu/drm-uapi.rst | 6 + drivers/gpu/drm/drm_drv.c | 3 + drivers/gpu/drm/drm_print.c | 209 ++++++++++++++++++++++++++++----- include/drm/drm_print.h | 63 ++++++++-- 4 files changed, 241 insertions(+), 40 deletions(-)

...

...
...
#include <drm/drm.h> #include <drm/drm_drv.h> @@ -43,17 +44,34 @@ unsigned int __drm_debug_syslog; EXPORT_SYMBOL(__drm_debug_syslog);

-MODULE_PARM_DESC(debug, "Enable debug output, where each bit enables a debug category.\n" -"\t\tBit 0 (0x01) will enable CORE messages (drm core code)\n" -"\t\tBit 1 (0x02) will enable DRIVER messages (drm controller code)\n" -"\t\tBit 2 (0x04) will enable KMS messages (modesetting code)\n" -"\t\tBit 3 (0x08) will enable PRIME messages (prime code)\n" -"\t\tBit 4 (0x10) will enable ATOMIC messages (atomic code)\n" -"\t\tBit 5 (0x20) will enable VBL messages (vblank code)\n" -"\t\tBit 7 (0x80) will enable LEASE messages (leasing code)\n" -"\t\tBit 8 (0x100) will enable DP messages (displayport code)"); +/*

__drm_debug_trace: Enable debug output in drm tracing instance.

Bitmask of DRM_UT_x. See include/drm/drm_print.h for details.

*/

+unsigned int __drm_debug_trace; +EXPORT_SYMBOL(__drm_debug_trace);

Hi!

Hi Pekka, Thanks again for the feedback, I'm happy that we seem to be converging!

...
Might distributions perhaps want to set a default value for this via Kconfig? Or could setting it via sysfs happen early enough to diagnose e.g. Plymouth problems?

Or maybe there is nothing to see from early boot?

The general usefulness of this feature depends on whether people actually run with it enabled.

I had assumed that the cmdline argument would be sufficient for distros, is Kconfig preferable here? The module parameter has the advantage of being runtime configurable and is more in line with drm.debug. We can do either in CrOS, so I'm happy to go with crowd consensus.

Hi,

I don't know. I did mean only *default* value for the module parameter via Kconfig. Right now your default value is implicit 0.

But that's just me thinking that making kernel command lines even longer would be somehow bad. Maybe it's fine?

Thanks, pq

Sean Paul

29 Jun 29 Jun

4:42 p.m.

On Mon, Jun 8, 2020 at 5:05 PM Sean Paul sean@poorly.run wrote:

...

From: Sean Paul seanpaul@chromium.org

This series is the latest in my journey to create a lightweight, always-on "flight recorder" (name credit Weston) of drm logs. This incarnation uses a trace_array to keep logs in memory exposed through tracefs. Users and distros can enable drm logs by using the drm.trace module parameter to choose the debug categories they are interested in.

The set has ballooned a little bit since the last version. Reason being is that I decided to return true from drm_debug_enabled if trace was enabled. This should make it easier and more seamless for driver developers to use the correct interface, but meant I needed to audit all uses of drm_debug_enabled and drm_debug_printer.

Out of all those calls, there are 3 situations which arose: 1- The logs should only go to syslog: I've converted these to use the drm_debug_syslog variant of enable check/printer.

2- The logs should go to both syslog/trace, but were using pr_debug(): I've converted these to use the proper drm logging helper. In cases which used a drm_printer I've had to use a new drm_debug_category_printer to ensure they are routed correctly.

3- The logs should go to both syslog/trace and are using drm logging fns: These are untouched and should be routed to the appropriate place(s)

Friendly ping. Is this something upstream wants, or should we continue carrying it downstream?

Sean

...

Sean Paul (13): drm/mipi_dbi: Convert pr_debug calls to DRM_DEBUG_DRIVER drm/sil164: Convert dev_printk to drm_dev_dbg drm/i915/utils: Replace dev_printk with drm helpers drm/msm/dpu: Replace definitions for dpu debug macros drm/print: rename drm_debug* to be more syslog-centric drm/amd: Gate i2c transaction logs on drm_debug_syslog drm/etnaviv: Change buffer dump checks to target syslog drm/nouveau: Change debug checks to specifically target syslog drm/i915: Change infoframe debug checks to specify syslog drm/print: Add drm_debug_category_printer drm/mst: Convert debug printers to debug category printers drm/i915: Use debug category printer for welcome message drm/print: Add tracefs support to the drm logging helpers

Documentation/gpu/drm-uapi.rst | 6 + drivers/gpu/drm/amd/amdgpu/smu_v11_0_i2c.c | 4 +- drivers/gpu/drm/drm_dp_mst_topology.c | 9 +- drivers/gpu/drm/drm_drv.c | 3 + drivers/gpu/drm/drm_mipi_dbi.c | 8 +- drivers/gpu/drm/drm_print.c | 228 ++++++++++++++++--- drivers/gpu/drm/etnaviv/etnaviv_buffer.c | 8 +- drivers/gpu/drm/i2c/sil164_drv.c | 12 +- drivers/gpu/drm/i915/display/intel_display.c | 4 +- drivers/gpu/drm/i915/i915_drv.c | 3 +- drivers/gpu/drm/i915/i915_utils.c | 5 +- drivers/gpu/drm/msm/disp/dpu1/dpu_kms.h | 20 +- drivers/gpu/drm/nouveau/dispnv50/disp.h | 4 +- drivers/gpu/drm/nouveau/nouveau_drv.h | 4 +- include/drm/drm_print.h | 96 +++++++- 15 files changed, 318 insertions(+), 96 deletions(-)

-- Sean Paul, Software Engineer, Google / Chromium OS

1784

Age (days ago)

1805

Last active (days ago)

dri-devel@lists.freedesktop.org

25 comments

6 participants

tags (0)

participants (6)

Christian König
kernel test robot
Pekka Paalanen
Sam Ravnborg
Sean Paul
Steven Rostedt