Nouveau - Jun 2024 - [PATCH 2/2] [v5] drm/nouveau: expose GSP-RM logging buffers via debugfs

Hi Timur,

thanks for the follow-up on this patch series.

On Wed, Jun 12, 2024 at 06:52:53PM -0500, Timur Tabi
wrote:
> The LOGINIT, LOGINTR, LOGRM, and LOGPMU buffers are circular buffers
> that have printf-like logs from GSP-RM and PMU encoded in them.
> 
> LOGINIT, LOGINTR, and LOGRM are allocated by Nouveau and their DMA
> addresses are passed to GSP-RM during initialization.  The buffers are
> required for GSP-RM to initialize properly.
> 
> LOGPMU is also allocated by Nouveau, but its contents are updated
> when Nouveau receives an NV_VGPU_MSG_EVENT_UCODE_LIBOS_PRINT RPC from
> GSP-RM.  Nouveau then copies the RPC to the buffer.
> 
> The messages are encoded as an array of variable-length structures that
> contain the parameters to an NV_PRINTF call.  The format string and
> parameter count are stored in a special ELF image that contains only
> logging strings.  This image is not currently shipped with the Nvidia
> driver.
> 
> There are two methods to extract the logs.
> 
> OpenRM tries to load the logging ELF, and if present, parses the log
> buffers in real time and outputs the strings to the kernel console.
> 
> Alternatively, and this is the method used by this patch, the buffers
> can be exposed to user space, and a user-space tool (along with the
> logging ELF image) can parse the buffer and dump the logs.
> 
> This method has the advantage that it allows the buffers to be parsed
> even when the logging ELF file is not available to the user.  However,
> it has the disadvantage the debubfs entries need to remain until the
> driver is unloaded.
> 
> The buffers are exposed via debugfs.  If GSP-RM fails to initialize,
> then Nouveau immediately shuts down the GSP interface.  This would
> normally also deallocate the logging buffers, thereby preventing the
> user from capturing the debug logs.
> 
> To avoid this, introduce the keep-gsp-logging command line parameter.
> If specified, and if at least one logging buffer has content, then
> Nouveau will migrate these buffers into new debugfs entries that are
> retained until the driver unloads.
> 
> An end-user can capture the logs using the following commands:
> 
>     cp /sys/kernel/debug/dri/<path>/loginit loginit
>     cp /sys/kernel/debug/dri/<path>/logrm logrm
>     cp /sys/kernel/debug/dri/<path>/logintr logintr
>     cp /sys/kernel/debug/dri/<path>/logpmu logpmu
> 
> where <path> is the PCI ID of the GPU (e.g. 0000:65:00.0).
> 
> Since LOGPMU is not needed for normal GSP-RM operation, it is only
> created if debugfs is available.  Otherwise, the
> NV_VGPU_MSG_EVENT_UCODE_LIBOS_PRINT RPCs are ignored.
> 
> Signed-off-by: Timur Tabi <ttabi at nvidia.com>
> ---
> v5:
> rebased to drm-misc-next
> repaced nvkm_gsp_log with nvif_log
> minor rearrangement of some code
> 
>  drivers/gpu/drm/nouveau/include/nvif/log.h    |  32 ++
>  .../gpu/drm/nouveau/include/nvkm/subdev/gsp.h |  13 +
>  drivers/gpu/drm/nouveau/nouveau_drm.c         |  19 +
>  .../gpu/drm/nouveau/nvkm/subdev/gsp/r535.c    | 360 +++++++++++++++++-
>  4 files changed, 423 insertions(+), 1 deletion(-)
>  create mode 100644 drivers/gpu/drm/nouveau/include/nvif/log.h
> 
> diff --git a/drivers/gpu/drm/nouveau/include/nvif/log.h
b/drivers/gpu/drm/nouveau/include/nvif/log.h
> new file mode 100644
> index 000000000000..c89ba85a701d
> --- /dev/null
> +++ b/drivers/gpu/drm/nouveau/include/nvif/log.h
> @@ -0,0 +1,32 @@
> +/* SPDX-License-Identifier: MIT */
> +/* SPDX-FileCopyrightText: Copyright (c) 2024 NVIDIA CORPORATION &
AFFILIATES. */
> +
> +#ifndef __NVIF_LOG_H__
> +#define __NVIF_LOG_H__
> +
> +/**
> + * nvif_log - structure for tracking logging buffers
> + * @head: list head
What about "@entry: an entry in a list of struct nvif_logs".
> + * @shutdown: pointer to function to call to clean up
I'd be a bit more specific and say that this frees all backing resources,
such
as logging buffer, etc.
> + *
> + * Structure used to track logging buffers so that they can be cleaned up
> + * when the driver exits.
> + */
> +struct nvif_log {
> +	struct list_head head;
I suggest to call this 'entry', since that's what it actually
represents, and
entry in a list.
> +	void (*shutdown)(struct nvif_log *log);
> +};
> +
> +#ifdef CONFIG_DEBUG_FS
> +/**
> + * gsp_logs - list of nvif_log GSP-RM logging buffers
> + *
> + * Head pointer to a a list of nvif_log buffers that is created for each
GPU
> + * upon GSP shutdown if the "keep_gsp_logging" command-line
parameter is
> + * specified.  This is used to track the alternative debugfs entries for
the
> + * GSP-RM logs.
> + */
> +extern struct list_head gsp_logs;
Better wrap this in a struct nvif_logs (or similar) and pass this down through
nvkm_device_pci_new() / nvkm_device_tegra_new() instead of relying on sharing
a global.
> +#endif
> +
> +#endif
> diff --git a/drivers/gpu/drm/nouveau/include/nvkm/subdev/gsp.h
b/drivers/gpu/drm/nouveau/include/nvkm/subdev/gsp.h
> index a45a4ad843b9..836443fd5659 100644
> --- a/drivers/gpu/drm/nouveau/include/nvkm/subdev/gsp.h
> +++ b/drivers/gpu/drm/nouveau/include/nvkm/subdev/gsp.h
> @@ -5,6 +5,8 @@
>  #include <core/falcon.h>
>  #include <core/firmware.h>
>  
> +#include <linux/debugfs.h>
> +
>  #define GSP_PAGE_SHIFT 12
>  #define GSP_PAGE_SIZE  BIT(GSP_PAGE_SHIFT)
>  
> @@ -220,6 +222,17 @@ struct nvkm_gsp {
>  
>  	/* The size of the registry RPC */
>  	size_t registry_rpc_size;
> +
> +#ifdef CONFIG_DEBUG_FS
> +	/*
> +	 * Logging buffers in debugfs.  The wrapper objects need to remain
> +	 * in memory until the dentry is deleted.
> +	 */
> +	struct debugfs_blob_wrapper blob_init;
> +	struct debugfs_blob_wrapper blob_intr;
> +	struct debugfs_blob_wrapper blob_rm;
> +	struct debugfs_blob_wrapper blob_pmu;
> +#endif
>  };
>  
>  static inline bool
> diff --git a/drivers/gpu/drm/nouveau/nouveau_drm.c
b/drivers/gpu/drm/nouveau/nouveau_drm.c
> index a58c31089613..3d0fa1f64872 100644
> --- a/drivers/gpu/drm/nouveau/nouveau_drm.c
> +++ b/drivers/gpu/drm/nouveau/nouveau_drm.c
> @@ -46,6 +46,7 @@
>  #include <nvif/fifo.h>
>  #include <nvif/push006c.h>
>  #include <nvif/user.h>
> +#include <nvif/log.h>
>  
>  #include <nvif/class.h>
>  #include <nvif/cl0002.h>
> @@ -113,6 +114,13 @@ static struct drm_driver driver_stub;
>  static struct drm_driver driver_pci;
>  static struct drm_driver driver_platform;
>  
> +#ifdef CONFIG_DEBUG_FS
> +/**
> + * gsp_logs - list of GSP debugfs logging buffers
> + */
> +LIST_HEAD(gsp_logs);
Better wrap this in a NVIF_LOGS_DECLARE() macro.
> +#endif
> +
>  static u64
>  nouveau_pci_name(struct pci_dev *pdev)
>  {
> @@ -1446,6 +1454,17 @@ nouveau_drm_exit(void)
>  #endif
>  	if (IS_ENABLED(CONFIG_DRM_NOUVEAU_SVM))
>  		mmu_notifier_synchronize();
> +
> +#ifdef CONFIG_DEBUG_FS
> +	if (!list_empty(&gsp_logs)) {
> +		struct nvif_log *log, *n;
> +
> +		list_for_each_entry_safe(log, n, &gsp_logs, head) {
> +			/* shutdown() should also delete the log entry */
> +			log->shutdown(log);
> +		}
> +	}
> +#endif
Please move this to include/nvif/log.h as nvif_log_shutdown().
>  }
>  
>  module_init(nouveau_drm_init);
> diff --git a/drivers/gpu/drm/nouveau/nvkm/subdev/gsp/r535.c
b/drivers/gpu/drm/nouveau/nvkm/subdev/gsp/r535.c
> index bbab6d452aa2..51ac66031b06 100644
> --- a/drivers/gpu/drm/nouveau/nvkm/subdev/gsp/r535.c
> +++ b/drivers/gpu/drm/nouveau/nvkm/subdev/gsp/r535.c
> @@ -26,6 +26,8 @@
>  #include <subdev/vfn.h>
>  #include <engine/fifo/chan.h>
>  #include <engine/sec2.h>
> +#include <drm/drm_device.h>
> +#include <nvif/log.h>
>  
>  #include <nvfw/fw.h>
>  
> @@ -2062,6 +2064,169 @@ r535_gsp_rmargs_init(struct nvkm_gsp *gsp, bool
resume)
>  	return 0;
>  }
>  
> +#ifdef CONFIG_DEBUG_FS
> +
> +/*
> + * If GSP-RM load fails, then the GSP nvkm object will be deleted, the
> + * logging debugfs entries will be deleted, and it will not be possible to
> + * debug the load failure.  The keep_gsp_logging parameter tells Nouveau
> + * to copy the logging buffers to new debugfs entries, and these entries
are
> + * retained until the driver unloads.
> + */
> +static bool keep_gsp_logging;
> +module_param(keep_gsp_logging, bool, 0444);
> +MODULE_PARM_DESC(keep_gsp_logging,
> +		 "Migrate the GSP-RM logging debugfs entries upon exit");
> +
> +#define NV_GSP_MSG_EVENT_UCODE_LIBOS_CLASS_PMU		0xf3d722
> +
> +/**
> + * r535_gsp_msg_libos_print - capture log message from the PMU
> + * @priv: gsp pointer
> + * @fn: function number (ignored)
> + * @repv: pointer to libos print RPC
> + * @repc: message size
> + *
> + * See _kgspRpcUcodeLibosPrint
What is this reference?
> + */
> +static int r535_gsp_msg_libos_print(void *priv, u32 fn, void *repv, u32
repc)
> +{
> +	struct nvkm_gsp *gsp = priv;
> +	struct nvkm_subdev *subdev = &gsp->subdev;
> +	struct {
> +		u32 ucodeEngDesc;
> +		u32 libosPrintBufSize;
> +		u8 libosPrintBuf[];
Why are those camelCase? Please use snake_case instead.

Also, please add a few notes on the fields GSP returns to us here. Admittedly,
two of those seem rather obvious - a log buffer and a size - but maybe we can
write down whether there is some maximum or minimum size? Can we get called with
a zero-size buffer?

What about 'ucodeEngDesc'? This one seems to behave more like a register
value,
can we document the "register layout" for this one?
> +	} *rpc = repv;
> +	unsigned int class = rpc->ucodeEngDesc >> 8;
> +
> +	nvkm_debug(subdev, "received libos print from class 0x%x for %u
bytes\n",
> +		   class, rpc->libosPrintBufSize);
> +
> +	if (class != NV_GSP_MSG_EVENT_UCODE_LIBOS_CLASS_PMU) {
> +		nvkm_warn(subdev,
> +			  "received libos print from unknown class 0x%x\n",
> +			  class);
> +		return -ENOMSG;
> +	}
> +
> +	if (rpc->libosPrintBufSize > GSP_PAGE_SIZE) {
> +		nvkm_error(subdev, "libos print is too large (%u bytes)\n",
> +			   rpc->libosPrintBufSize);
> +		return -E2BIG;
> +	}
> +
> +	memcpy(gsp->blob_pmu.data, rpc->libosPrintBuf,
rpc->libosPrintBufSize);
> +
> +	return 0;
> +}
> +
> +/**
> + * r535_gsp_libos_debugfs_init - create logging debugfs entries
> + * @gsp: gsp pointer
> + *
> + * Create the debugfs entries.  This exposes the log buffers to
> + * userspace so that an external tool can parse it.
> + *
> + * The 'logpmu' contains exception dumps from the PMU. It is
written via an
> + * RPC sent from GSP-RM and must be only 4KB.  We create it here because
it's
> + * only useful if there is a debugfs entry to expose it.  If we get the
PMU
> + * logging RPC and there is no debugfs entry, the RPC is just ignored.
> + *
> + * The blob_init, blob_rm, and blob_pmu objects can't be transient
> + * because debugfs_create_blob doesn't copy them.
> + *
> + * NOTE: OpenRM loads the logging elf image and prints the log messages
> + * in real-time. We may add that capability in the future, but that
> + * requires loading an ELF images that are not distributed with the
driver,
> + * and adding the parsing code to Nouveau.
> + *
> + * Ideally, this should be part of nouveau_debugfs_init(), but that
function
> + * is called too late.  We really want to create these debugfs entries
before
> + * r535_gsp_booter_load() is called, so that if GSP-RM fails to
initialize,
> + * there could still be a log to capture.
> + */
> +static void r535_gsp_libos_debugfs_init(struct nvkm_gsp *gsp)
> +{
> +	struct dentry *dir, *dir_init;
> +	struct dentry *dir_intr = NULL, *dir_rm = NULL, *dir_pmu = NULL;
> +	struct device *dev = gsp->subdev.device->dev;
> +
> +	/* Each GPU has a subdir based on its device name, so find it */
> +	struct drm_device *drm_dev = dev_get_drvdata(dev);
> +
> +	if (!drm_dev || !drm_dev->debugfs_root) {
> +		nvkm_error(&gsp->subdev, "could not find debugfs
path\n");
> +		return;
> +	}
> +
> +	dir = drm_dev->debugfs_root;
> +
> +	gsp->blob_init.data = gsp->loginit.data;
> +	gsp->blob_init.size = gsp->loginit.size;
> +	gsp->blob_intr.data = gsp->logintr.data;
> +	gsp->blob_intr.size = gsp->logintr.size;
> +	gsp->blob_rm.data = gsp->logrm.data;
> +	gsp->blob_rm.size = gsp->logrm.size;
> +
> +	dir_init = debugfs_create_blob("loginit", 0444, dir,
&gsp->blob_init);
> +	if (IS_ERR(dir_init)) {
> +		nvkm_error(&gsp->subdev, "failed to create loginit debugfs
entry\n");
> +		goto error;
> +	}
> +
> +	dir_intr = debugfs_create_blob("logintr", 0444, dir,
&gsp->blob_intr);
> +	if (IS_ERR(dir_intr)) {
> +		nvkm_error(&gsp->subdev, "failed to create logintr debugfs
entry\n");
> +		goto error;
> +	}
> +
> +	dir_rm = debugfs_create_blob("logrm", 0444, dir,
&gsp->blob_rm);
> +	if (IS_ERR(dir_rm)) {
> +		nvkm_error(&gsp->subdev, "failed to create logrm debugfs
entry\n");
> +		goto error;
> +	}
> +
> +	/*
> +	 * Since the PMU buffer is copied from an RPC, it doesn't need to be
> +	 * a DMA buffer.
> +	 */
> +	gsp->blob_pmu.size = GSP_PAGE_SIZE;
> +	gsp->blob_pmu.data = kzalloc(gsp->blob_pmu.size, GFP_KERNEL);
> +	if (!gsp->blob_pmu.data)
> +		goto error;
> +
> +	dir_pmu = debugfs_create_blob("logpmu", 0444, dir,
&gsp->blob_pmu);
> +	if (IS_ERR(dir_pmu)) {
> +		nvkm_error(&gsp->subdev, "failed to create logpmu debugfs
entry\n");
> +		kfree(gsp->blob_pmu.data);
> +		goto error;
> +	}
> +
> +	i_size_write(d_inode(dir_init), gsp->blob_init.size);
> +	i_size_write(d_inode(dir_intr), gsp->blob_intr.size);
> +	i_size_write(d_inode(dir_rm), gsp->blob_rm.size);
> +	i_size_write(d_inode(dir_pmu), gsp->blob_pmu.size);
> +
> +	r535_gsp_msg_ntfy_add(gsp, 0x0000100C, r535_gsp_msg_libos_print, gsp);
Please, don't add random magic values. Add a useful explanation instead that
also new contributors are able to make sense of.
> +
> +	nvkm_debug(&gsp->subdev, "created debugfs GSP-RM logging
entries\n");
> +
> +	if (keep_gsp_logging) {
> +		nvkm_warn(&gsp->subdev,
> +			  "logging buffers will be retained on failure\n");
> +	}
> +
> +	return;
> +
> +error:
> +	debugfs_remove(dir_init);
> +	debugfs_remove(dir_intr);
> +	debugfs_remove(dir_rm);
> +}
> +
> +#endif
> +
>  static inline u64
>  r535_gsp_libos_id8(const char *name)
>  {
> @@ -2112,7 +2277,11 @@ static void create_pte_array(u64 *ptes, dma_addr_t
addr, size_t size)
>   * written to directly by GSP-RM and can be any multiple of GSP_PAGE_SIZE.
>   *
>   * The physical address map for the log buffer is stored in the buffer
> - * itself, starting with offset 1. Offset 0 contains the "put"
pointer.
> + * itself, starting with offset 1. Offset 0 contains the "put"
pointer (pp).
> + * Initially, pp is equal to 0.  If the buffer has valid logging data in
it,
> + * then pp points to index into the buffer where the next logging entry
will
> + * be written.  Therefore, the logging data is valid if:
> + *   1 <= pp < sizeof(buffer)/sizeof(u64)
>   *
>   * The GSP only understands 4K pages (GSP_PAGE_SIZE), so even if the
kernel is
>   * configured for a larger page size (e.g. 64K pages), we need to give
> @@ -2183,6 +2352,11 @@ r535_gsp_libos_init(struct nvkm_gsp *gsp)
>  	args[3].size = gsp->rmargs.size;
>  	args[3].kind = LIBOS_MEMORY_REGION_CONTIGUOUS;
>  	args[3].loc  = LIBOS_MEMORY_REGION_LOC_SYSMEM;
> +
> +#ifdef CONFIG_DEBUG_FS
> +	r535_gsp_libos_debugfs_init(gsp);
> +#endif
> +
>  	return 0;
>  }
>  
> @@ -2493,6 +2667,182 @@ r535_gsp_dtor_fws(struct nvkm_gsp *gsp)
>  	gsp->fws.rm = NULL;
>  }
>  
> +#ifdef CONFIG_DEBUG_FS
> +
> +struct r535_gsp_log {
> +	struct nvif_log log;
> +
> +	/*
> +	 * Logging buffers in debugfs.  The wrapper objects need to remain
> +	 * in memory until the dentry is deleted.
> +	 */
> +	struct dentry *debugfs_logging_dir;
> +	struct debugfs_blob_wrapper blob_init;
> +	struct debugfs_blob_wrapper blob_intr;
> +	struct debugfs_blob_wrapper blob_rm;
> +	struct debugfs_blob_wrapper blob_pmu;
> +};
> +
> +/**
> + * r535_debugfs_shutdown - delete GSP-RM logging buffers for one GPU
> + * @_log: nvif_log struct for this GPU
> + *
> + * Called when the driver is shutting down, to clean up the retained
GSP-RM
> + * logging buffers.
> + */
> +static void r535_debugfs_shutdown(struct nvif_log *_log)
> +{
> +	struct r535_gsp_log *log = container_of(_log, struct r535_gsp_log, log);
> +
> +	debugfs_remove(log->debugfs_logging_dir);
> +
> +	kfree(log->blob_init.data);
> +	kfree(log->blob_intr.data);
> +	kfree(log->blob_rm.data);
> +	kfree(log->blob_pmu.data);
> +
> +	/* We also need to delete the list object */
> +	kfree(log);
> +}
> +
> +/**
> + * is_empty - return true if the logging buffer was never written to
> + * @b: blob wrapper with ->data field pointing to logging buffer
> + *
> + * The first 64-bit field of loginit, and logintr, and logrm is the
'put'
> + * pointer, and it is initialized to 0.  If the pointer is still 0 when
Double space. Also, what would 'put' point to in case it's non-zero?
Is it a
pointer actually, or is it just some kind of counter?
> + * GSP-RM is shut down, that means that it was never written do, so it
"written to"
> + * can be ignored.
> + *
> + * This test also works for logpmu, even though it doesn't have a put
pointer.
> + */
> +static bool is_empty(struct debugfs_blob_wrapper *b)
> +{
> +	u64 *put = b->data;
> +
> +	return *put == 0;
> +}
> +
> +static int r535_gsp_copy_log(struct dentry *parent,
> +			     const char *name,
> +			     struct debugfs_blob_wrapper *s,
> +			     struct debugfs_blob_wrapper *d)
> +{
> +	struct dentry *dir;
> +
> +	/* If the buffer is empty, just skip it. */
> +	if (is_empty(s))
> +		return 0;
> +
> +	d->data = kmemdup(s->data, s->size, GFP_KERNEL);
> +	if (!d->data)
> +		return -ENOMEM;
> +
> +	d->size = s->size;
> +	dir = debugfs_create_blob(name, 0444, parent, d);
> +	if (IS_ERR(dir)) {
> +		kfree(d->data);
> +		memset(d, 0, sizeof(*d));
> +		return PTR_ERR(dir);
> +	}
> +
> +	i_size_write(d_inode(dir), d->size);
> +
> +	return 0;
> +}
> +
> +/**
> + * r535_gsp_retain_logging - copy logging buffers to new debugfs root
> + * @gsp: gsp pointer
> + *
> + * If keep_gsp_logging is enabled, then we want to preserve the GSP-RM
logging
> + * buffers and their debugfs entries, but all those objects would normally
> + * deleted if GSP-RM fails to load.  So we create a new debugfs root,
allocate
> + * new buffers, then and copy contents of the logging buffers to them.
> + *
> + * These buffers and dentries are not associated with nvkm_gsp and will be
> + * retained until the driver unloads.
> + */
> +static void r535_gsp_retain_logging(struct nvkm_gsp *gsp)
> +{
> +	struct device *dev = gsp->subdev.device->dev;
> +	struct dentry *root, *dir;
> +	struct r535_gsp_log *log;
> +	int ret;
> +
> +	/* If we were told not to keep logs, then don't. */
> +	if (!keep_gsp_logging)
> +		return;
> +
> +	/* Check to make sure at least one buffer has data. */
> +	if (is_empty(&gsp->blob_init) &&
is_empty(&gsp->blob_intr) &&
> +	    is_empty(&gsp->blob_rm) &&
is_empty(&gsp->blob_rm)) {
> +		nvkm_warn(&gsp->subdev, "all logging buffers are
empty\n");
> +		return;
> +	}
> +
> +	/* Find the 'dri' root debugfs entry. Every GPU has a dentry
under it */
> +	root = debugfs_lookup("dri", NULL);
> +	if (IS_ERR(root)) {
> +		/* No debugfs, or no root dentry for DRM */
> +		nvkm_warn(&gsp->subdev, "could not find debugfs dri
root\n");
> +		return;
> +	}
> +
> +	/* Create a new debugfs root. It has the same name as the old one */
> +	dir = debugfs_create_dir(dev_name(dev), root);
> +	dput(root);
> +	if (IS_ERR(dir)) {
> +		nvkm_error(&gsp->subdev,
> +			   "failed to create %s debugfs entry\n", dev_name(dev));
> +		return;
> +	}
> +
> +	log = kzalloc(sizeof(*log), GFP_KERNEL);
> +	if (!log) {
> +		debugfs_remove(dir);
> +		return;
> +	}
> +
> +	ret = r535_gsp_copy_log(dir, "loginit", &gsp->blob_init,
&log->blob_init);
> +	if (ret)
> +		goto error;
> +
> +	ret = r535_gsp_copy_log(dir, "logintr", &gsp->blob_intr,
&log->blob_intr);
> +	if (ret)
> +		goto error;
> +
> +	ret = r535_gsp_copy_log(dir, "logrm", &gsp->blob_rm,
&log->blob_rm);
> +	if (ret)
> +		goto error;
> +
> +	ret = r535_gsp_copy_log(dir, "logpmu", &gsp->blob_pmu,
&log->blob_pmu);
> +	if (ret)
> +		goto error;
> +
> +	log->debugfs_logging_dir = dir;
> +	log->log.shutdown = r535_debugfs_shutdown;
> +	list_add(&log->log.head, &gsp_logs);
> +
> +	nvkm_warn(&gsp->subdev,
> +		  "logging buffers migrated to /sys/kernel/debug/dri/%s\n",
> +		  dev_name(dev));
> +
> +	return;
> +
> +error:
> +	nvkm_warn(&gsp->subdev, "failed to migrate logging
buffers\n");
> +
> +	debugfs_remove(log->debugfs_logging_dir);
> +	kfree(log->blob_init.data);
> +	kfree(log->blob_intr.data);
> +	kfree(log->blob_rm.data);
> +	kfree(log->blob_pmu.data);
> +	kfree(log);
> +}
> +
> +#endif
> +
>  void
>  r535_gsp_dtor(struct nvkm_gsp *gsp)
>  {
> @@ -2514,6 +2864,14 @@ r535_gsp_dtor(struct nvkm_gsp *gsp)
>  	nvkm_gsp_mem_dtor(&gsp->rmargs);
>  	nvkm_gsp_mem_dtor(&gsp->wpr_meta);
>  	nvkm_gsp_mem_dtor(&gsp->shm.mem);
> +
> +#ifdef CONFIG_DEBUG_FS
> +	r535_gsp_retain_logging(gsp);
> +
> +	kfree(gsp->blob_pmu.data);
> +	gsp->blob_pmu.data = NULL;
Please move this to r535_gsp_libos_debugfs_fini() to make it a bit more obvious
why this needs to be cleaned up here.
> +#endif
> +
>  	nvkm_gsp_mem_dtor(&gsp->loginit);
>  	nvkm_gsp_mem_dtor(&gsp->logintr);
>  	nvkm_gsp_mem_dtor(&gsp->logrm);
> -- 
> 2.34.1
>

On Mon, 2024-06-17 at 21:54 +0200, Danilo Krummrich wrote:

Hi Timur,


thanks for the follow-up on this patch series.


On Wed, Jun 12, 2024 at 06:52:53PM -0500, Timur Tabi wrote:

The LOGINIT, LOGINTR, LOGRM, and LOGPMU buffers are circular buffers

that have printf-like logs from GSP-RM and PMU encoded in them.


LOGINIT, LOGINTR, and LOGRM are allocated by Nouveau and their DMA

addresses are passed to GSP-RM during initialization.  The buffers are

required for GSP-RM to initialize properly.


LOGPMU is also allocated by Nouveau, but its contents are updated

when Nouveau receives an NV_VGPU_MSG_EVENT_UCODE_LIBOS_PRINT RPC from

GSP-RM.  Nouveau then copies the RPC to the buffer.


The messages are encoded as an array of variable-length structures that

contain the parameters to an NV_PRINTF call.  The format string and

parameter count are stored in a special ELF image that contains only

logging strings.  This image is not currently shipped with the Nvidia

driver.


There are two methods to extract the logs.


OpenRM tries to load the logging ELF, and if present, parses the log

buffers in real time and outputs the strings to the kernel console.


Alternatively, and this is the method used by this patch, the buffers

can be exposed to user space, and a user-space tool (along with the

logging ELF image) can parse the buffer and dump the logs.


This method has the advantage that it allows the buffers to be parsed

even when the logging ELF file is not available to the user.  However,

it has the disadvantage the debubfs entries need to remain until the

driver is unloaded.


The buffers are exposed via debugfs.  If GSP-RM fails to initialize,

then Nouveau immediately shuts down the GSP interface.  This would

normally also deallocate the logging buffers, thereby preventing the

user from capturing the debug logs.


To avoid this, introduce the keep-gsp-logging command line parameter.

If specified, and if at least one logging buffer has content, then

Nouveau will migrate these buffers into new debugfs entries that are

retained until the driver unloads.


An end-user can capture the logs using the following commands:


    cp /sys/kernel/debug/dri/<path>/loginit loginit

    cp /sys/kernel/debug/dri/<path>/logrm logrm

    cp /sys/kernel/debug/dri/<path>/logintr logintr

    cp /sys/kernel/debug/dri/<path>/logpmu logpmu


where <path> is the PCI ID of the GPU (e.g. 0000:65:00.0).


Since LOGPMU is not needed for normal GSP-RM operation, it is only

created if debugfs is available.  Otherwise, the

NV_VGPU_MSG_EVENT_UCODE_LIBOS_PRINT RPCs are ignored.


Signed-off-by: Timur Tabi <ttabi at nvidia.com<mailto:ttabi at
nvidia.com>>

---

v5:

rebased to drm-misc-next

repaced nvkm_gsp_log with nvif_log

minor rearrangement of some code


 drivers/gpu/drm/nouveau/include/nvif/log.h    |  32 ++

 .../gpu/drm/nouveau/include/nvkm/subdev/gsp.h |  13 +

 drivers/gpu/drm/nouveau/nouveau_drm.c         |  19 +

 .../gpu/drm/nouveau/nvkm/subdev/gsp/r535.c    | 360 +++++++++++++++++-

 4 files changed, 423 insertions(+), 1 deletion(-)

 create mode 100644 drivers/gpu/drm/nouveau/include/nvif/log.h


diff --git a/drivers/gpu/drm/nouveau/include/nvif/log.h
b/drivers/gpu/drm/nouveau/include/nvif/log.h

new file mode 100644

index 000000000000..c89ba85a701d

--- /dev/null

+++ b/drivers/gpu/drm/nouveau/include/nvif/log.h

@@ -0,0 +1,32 @@

+/* SPDX-License-Identifier: MIT */

+/* SPDX-FileCopyrightText: Copyright (c) 2024 NVIDIA CORPORATION &
AFFILIATES. */

+

+#ifndef __NVIF_LOG_H__

+#define __NVIF_LOG_H__

+

+/**

+ * nvif_log - structure for tracking logging buffers

+ * @head: list head


What about "@entry: an entry in a list of struct nvif_logs".

Done.


+ * @shutdown: pointer to function to call to clean up


I'd be a bit more specific and say that this frees all backing resources,
such

as logging buffer, etc.

Done.



+ *

+ * Structure used to track logging buffers so that they can be cleaned up

+ * when the driver exits.

+ */

+struct nvif_log {

+       struct list_head head;


I suggest to call this 'entry', since that's what it actually
represents, and

entry in a list.

Oh yeah, I see what you mean now.  Done.


+       void (*shutdown)(struct nvif_log *log);

+};

+

+#ifdef CONFIG_DEBUG_FS

+/**

+ * gsp_logs - list of nvif_log GSP-RM logging buffers

+ *

+ * Head pointer to a a list of nvif_log buffers that is created for each GPU

+ * upon GSP shutdown if the "keep_gsp_logging" command-line parameter
is

+ * specified.  This is used to track the alternative debugfs entries for the

+ * GSP-RM logs.

+ */

+extern struct list_head gsp_logs;


Better wrap this in a struct nvif_logs (or similar) and pass this down through

nvkm_device_pci_new() / nvkm_device_tegra_new() instead of relying on sharing

a global.

I'm still having difficulty understanding what you mean by this.  I think
you need to be more explicit in what you want.

struct nvif_logs
{
struct list_head logs;
} gsp_logs;

First, I don't understand what this gets me.  It just wraps one struct
inside another.

Should I add this to struct nvkm_device_func?  And then do something like this
in pci.c:

static struct nvif_logs gsp_logs;

static const struct nvkm_device_func
nvkm_device_pci_func = {

...
.nvif_logs = &gsp_logs,
};

So nvkm_device_pci_new() calls nvkm_device_ctor().  nvkm_device_ctor() then
calls the .ctor() for every subdevice via NVKM_LAYOUT_ONCE() and
NVKM_LAYOUT_INST().  This is where I get lost, because I don't see how I
make sure only the GSP constructor tries to initialize gsp_logs.



+#ifdef CONFIG_DEBUG_FS

+/**

+ * gsp_logs - list of GSP debugfs logging buffers

+ */

+LIST_HEAD(gsp_logs);


Better wrap this in a NVIF_LOGS_DECLARE() macro.

Like this?

#define NVIF_LOGS_DECLARE(x) LIST_HEAD(x)

Do you want a macro to replace this as well?

extern struct list_head gsp_logs;



+#endif

+

 static u64

 nouveau_pci_name(struct pci_dev *pdev)

 {

@@ -1446,6 +1454,17 @@ nouveau_drm_exit(void)

 #endif

        if (IS_ENABLED(CONFIG_DRM_NOUVEAU_SVM))

                mmu_notifier_synchronize();

+

+#ifdef CONFIG_DEBUG_FS

+       if (!list_empty(&gsp_logs)) {

+               struct nvif_log *log, *n;

+

+               list_for_each_entry_safe(log, n, &gsp_logs, head) {

+                       /* shutdown() should also delete the log entry */

+                       log->shutdown(log);

+               }

+       }

+#endif


Please move this to include/nvif/log.h as nvif_log_shutdown().

Sure, but I don't understand why.  This code will only be called in
nouveau_drm_exit().


+/**

+ * r535_gsp_msg_libos_print - capture log message from the PMU

+ * @priv: gsp pointer

+ * @fn: function number (ignored)

+ * @repv: pointer to libos print RPC

+ * @repc: message size

+ *

+ * See _kgspRpcUcodeLibosPrint


What is this reference?

It's in OpenRM.  Pretty much all of the "See" commands are
references to the corresponding function in OpenRM".



+ */

+static int r535_gsp_msg_libos_print(void *priv, u32 fn, void *repv, u32 repc)

+{

+       struct nvkm_gsp *gsp = priv;

+       struct nvkm_subdev *subdev = &gsp->subdev;

+       struct {

+               u32 ucodeEngDesc;

+               u32 libosPrintBufSize;

+               u8 libosPrintBuf[];


Why are those camelCase? Please use snake_case instead.

Sure.  They match the names from OpenRM (see g_rpc-structures.h).  I'll
change them, though.  When I copy a struct directly from OpenRM, I prefer to
keep it as identical as possible to make it easier to see the connection.

I'll move this to a distinct struct and rename the fields.



Also, please add a few notes on the fields GSP returns to us here. Admittedly,

two of those seem rather obvious - a log buffer and a size - but maybe we can

write down whether there is some maximum or minimum size? Can we get called with

a zero-size buffer?


What about 'ucodeEngDesc'? This one seems to behave more like a register
value,

can we document the "register layout" for this one?

I've added some documentation.  Basically, the field is divided into a
"class ID" and an "instance ID".  I'm guessing the
instance ID is just a 0-based index for the engine.  The class ID is just some
seemingly random number that distinguishes the various engines.  Building RM
involves a lot of pre-processing with config files to generate much of the code
that is compiled, and these class IDs are one example.


+       i_size_write(d_inode(dir_init), gsp->blob_init.size);

+       i_size_write(d_inode(dir_intr), gsp->blob_intr.size);

+       i_size_write(d_inode(dir_rm), gsp->blob_rm.size);

+       i_size_write(d_inode(dir_pmu), gsp->blob_pmu.size);

+

+       r535_gsp_msg_ntfy_add(gsp, 0x0000100C, r535_gsp_msg_libos_print, gsp);


Please, don't add random magic values. Add a useful explanation instead that

also new contributors are able to make sense of.

Ah, I can just use the macro that's already defined in rpc_global_enums.h.



+

+       nvkm_debug(&gsp->subdev, "created debugfs GSP-RM logging
entries\n");

+

+       if (keep_gsp_logging) {

+               nvkm_warn(&gsp->subdev,

+                         "logging buffers will be retained on
failure\n");

+       }

+

+       return;

+

+error:

+       debugfs_remove(dir_init);

+       debugfs_remove(dir_intr);

+       debugfs_remove(dir_rm);

+}

+

+#endif

+

 static inline u64

 r535_gsp_libos_id8(const char *name)

 {

@@ -2112,7 +2277,11 @@ static void create_pte_array(u64 *ptes, dma_addr_t addr,
size_t size)

  * written to directly by GSP-RM and can be any multiple of GSP_PAGE_SIZE.

  *

  * The physical address map for the log buffer is stored in the buffer

- * itself, starting with offset 1. Offset 0 contains the "put"
pointer.

+ * itself, starting with offset 1. Offset 0 contains the "put"
pointer (pp).

+ * Initially, pp is equal to 0.  If the buffer has valid logging data in it,

+ * then pp points to index into the buffer where the next logging entry will

+ * be written.  Therefore, the logging data is valid if:

+ *   1 <= pp < sizeof(buffer)/sizeof(u64)

  *

  * The GSP only understands 4K pages (GSP_PAGE_SIZE), so even if the kernel is

  * configured for a larger page size (e.g. 64K pages), we need to give

@@ -2183,6 +2352,11 @@ r535_gsp_libos_init(struct nvkm_gsp *gsp)

        args[3].size = gsp->rmargs.size;

        args[3].kind = LIBOS_MEMORY_REGION_CONTIGUOUS;

        args[3].loc  = LIBOS_MEMORY_REGION_LOC_SYSMEM;

+

+#ifdef CONFIG_DEBUG_FS

+       r535_gsp_libos_debugfs_init(gsp);

+#endif

+

        return 0;

 }



@@ -2493,6 +2667,182 @@ r535_gsp_dtor_fws(struct nvkm_gsp *gsp)

        gsp->fws.rm = NULL;

 }



+#ifdef CONFIG_DEBUG_FS

+

+struct r535_gsp_log {

+       struct nvif_log log;

+

+       /*

+        * Logging buffers in debugfs.  The wrapper objects need to remain

+        * in memory until the dentry is deleted.

+        */

+       struct dentry *debugfs_logging_dir;

+       struct debugfs_blob_wrapper blob_init;

+       struct debugfs_blob_wrapper blob_intr;

+       struct debugfs_blob_wrapper blob_rm;

+       struct debugfs_blob_wrapper blob_pmu;

+};

+

+/**

+ * r535_debugfs_shutdown - delete GSP-RM logging buffers for one GPU

+ * @_log: nvif_log struct for this GPU

+ *

+ * Called when the driver is shutting down, to clean up the retained GSP-RM

+ * logging buffers.

+ */

+static void r535_debugfs_shutdown(struct nvif_log *_log)

+{

+       struct r535_gsp_log *log = container_of(_log, struct r535_gsp_log, log);

+

+       debugfs_remove(log->debugfs_logging_dir);

+

+       kfree(log->blob_init.data);

+       kfree(log->blob_intr.data);

+       kfree(log->blob_rm.data);

+       kfree(log->blob_pmu.data);

+

+       /* We also need to delete the list object */

+       kfree(log);

+}

+

+/**

+ * is_empty - return true if the logging buffer was never written to

+ * @b: blob wrapper with ->data field pointing to logging buffer

+ *

+ * The first 64-bit field of loginit, and logintr, and logrm is the
'put'

+ * pointer, and it is initialized to 0.  If the pointer is still 0 when


Double space.

Uh, are you only now noticing that I always put two spaces after a
"."?  I do that everywhere.


Also, what would 'put' point to in case it's non-zero? Is it a

pointer actually, or is it just some kind of counter?

It's called the "put pointer" internally, but it's actually a
dword-based index into the buffer.  So a value of 1 is an iffset of 4, a value
of 2 is an offset of 8, etc.

I'll update the docs.



+ * GSP-RM is shut down, that means that it was never written do, so it


"written to"

Fixed, thanks.



 void

 r535_gsp_dtor(struct nvkm_gsp *gsp)

 {

@@ -2514,6 +2864,14 @@ r535_gsp_dtor(struct nvkm_gsp *gsp)

        nvkm_gsp_mem_dtor(&gsp->rmargs);

        nvkm_gsp_mem_dtor(&gsp->wpr_meta);

        nvkm_gsp_mem_dtor(&gsp->shm.mem);

+

+#ifdef CONFIG_DEBUG_FS

+       r535_gsp_retain_logging(gsp);

+

+       kfree(gsp->blob_pmu.data);

+       gsp->blob_pmu.data = NULL;


Please move this to r535_gsp_libos_debugfs_fini() to make it a bit more obvious

why this needs to be cleaned up here.

So first, I made a mistake, and the #ifdef is only supposed to be around the
call to r535_gsp_retain_logging().

Second, are you saying you want this?

/**
 * r535_gsp_libos_debugfs_fini - retrain debugfs buffers if necessary
 *
 * bla bla some text about why we're doing this
 */
static void r535_gsp_libos_debugfs_fini(struct nvkm_gsp __maybe_unused *gsp)
{
#ifdef CONFIG_DEBUG_FS
r535_gsp_retain_logging(gsp);
#endif
}


-------------- next part --------------
An HTML attachment was scrubbed...
URL:
<https://lists.freedesktop.org/archives/nouveau/attachments/20240618/c386d0af/attachment-0001.htm>