2019-11-03 18:08:09

by Drew DeVault

[permalink] [raw]
Subject: [PATCH v2] firmware loader: log path to loaded firmwares


This is useful for users who are trying to identify the firmwares in use
on their system.

Signed-off-by: Drew DeVault <[email protected]>
---
v2 uses dev_dbg instead of printk(KERN_INFO)

drivers/base/firmware_loader/main.c | 1 +
1 file changed, 1 insertion(+)

diff --git a/drivers/base/firmware_loader/main.c b/drivers/base/firmware_loader/main.c
index bf44c79beae9..2537da43a572 100644
--- a/drivers/base/firmware_loader/main.c
+++ b/drivers/base/firmware_loader/main.c
@@ -504,6 +504,7 @@ fw_get_filesystem_firmware(struct device *device, struct fw_priv *fw_priv,
path);
continue;
}
+ dev_dbg(device, "Loading firmware from %s\n", path);
if (decompress) {
dev_dbg(device, "f/w decompressing %s\n",
fw_priv->fw_name);
--
2.23.0


2019-11-13 00:57:41

by Luis Chamberlain

[permalink] [raw]
Subject: Re: [PATCH v2] firmware loader: log path to loaded firmwares

On Sun, Nov 03, 2019 at 01:06:46PM -0500, Drew DeVault wrote:
>
> This is useful for users who are trying to identify the firmwares in use
> on their system.
>
> Signed-off-by: Drew DeVault <[email protected]>
> ---
> v2 uses dev_dbg instead of printk(KERN_INFO)
>
> drivers/base/firmware_loader/main.c | 1 +
> 1 file changed, 1 insertion(+)
>
> diff --git a/drivers/base/firmware_loader/main.c b/drivers/base/firmware_loader/main.c
> index bf44c79beae9..2537da43a572 100644
> --- a/drivers/base/firmware_loader/main.c
> +++ b/drivers/base/firmware_loader/main.c
> @@ -504,6 +504,7 @@ fw_get_filesystem_firmware(struct device *device, struct fw_priv *fw_priv,
> path);
> continue;
> }
> + dev_dbg(device, "Loading firmware from %s\n", path);

Because this is dev_dbg() I'm willing to consider it, so that its not
always enabled. However its not in the right place, the code path you
are addressing is only for direct filesystem lookups. If that fails
some systems do a fallback call out to userspace. To cover both cases,
you want it at the end of _request_firmware() on the success path. Can
you send a new patch?

Luis

> if (decompress) {
> dev_dbg(device, "f/w decompressing %s\n",
> fw_priv->fw_name);
> --
> 2.23.0
>

2019-11-13 14:07:06

by Drew DeVault

[permalink] [raw]
Subject: Re: [PATCH v2] firmware loader: log path to loaded firmwares

Sure, no problem. Thanks for clarifying.

2019-11-13 20:20:48

by Robin H. Johnson

[permalink] [raw]
Subject: Re: [PATCH v2] firmware loader: log path to loaded firmwares

On Wed, Nov 13, 2019 at 12:56:28AM +0000, Luis Chamberlain wrote:
> On Sun, Nov 03, 2019 at 01:06:46PM -0500, Drew DeVault wrote:
> >
> > This is useful for users who are trying to identify the firmwares in use
> > on their system.
> >
> > Signed-off-by: Drew DeVault <[email protected]>
> > ---
> > v2 uses dev_dbg instead of printk(KERN_INFO)
> >
> > drivers/base/firmware_loader/main.c | 1 +
> > 1 file changed, 1 insertion(+)
> >
> > diff --git a/drivers/base/firmware_loader/main.c b/drivers/base/firmware_loader/main.c
> > index bf44c79beae9..2537da43a572 100644
> > --- a/drivers/base/firmware_loader/main.c
> > +++ b/drivers/base/firmware_loader/main.c
> > @@ -504,6 +504,7 @@ fw_get_filesystem_firmware(struct device *device, struct fw_priv *fw_priv,
> > path);
> > continue;
> > }
> > + dev_dbg(device, "Loading firmware from %s\n", path);
>
> Because this is dev_dbg() I'm willing to consider it, so that its not
> always enabled. However its not in the right place, the code path you
> are addressing is only for direct filesystem lookups. If that fails
> some systems do a fallback call out to userspace. To cover both cases,
> you want it at the end of _request_firmware() on the success path. Can
> you send a new patch?
As the author of a separate patch that predates Drew's patch (originally
in July, with a later version sent to the list last week):
https://pastebin.com/Tf09x3ed (v1)
https://lkml.org/lkml/2019/11/7/800 (v2)

This already uses the _request_firmware path to fire after the firmware
was successfully loaded. The commit message is also specific that it's
to cover early boot situations, before UEVENT can be logged.

dev_dbg means that the loglevel must have been set to debug BEFORE the
firmware load took place, but this means either setting system-wide
debug spam or requiring debugfs, which is annoying for boot stuff (not
impossible, just annoying).

I have two uses cases overall:
- log so you know exactly when it's loaded successfully (great if
loading a firmware causes your system to lock up a few seconds later)
- at some point in the future, being able to query what firmware was
loaded in the past, and esp. exactly what version/data was in that
firmware file.

--
Robin Hugh Johnson
Gentoo Linux: Dev, Infra Lead, Foundation Treasurer
E-Mail : [email protected]
GnuPG FP : 11ACBA4F 4778E3F6 E4EDF38E B27B944E 34884E85
GnuPG FP : 7D0B3CEB E9B85B1F 825BCECF EE05E6F6 A48F6136


Attachments:
(No filename) (2.45 kB)
signature.asc (1.11 kB)
Download all attachments

2019-11-13 20:53:13

by Luis Chamberlain

[permalink] [raw]
Subject: Re: [PATCH v2] firmware loader: log path to loaded firmwares

On Wed, Nov 13, 2019 at 08:19:07PM +0000, Robin H. Johnson wrote:
> I have two uses cases overall:
> - log so you know exactly when it's loaded successfully (great if
> loading a firmware causes your system to lock up a few seconds later)

Then you can change the driver to confirm this, not impose every driver
to do the same.

> - at some point in the future, being able to query what firmware was
> loaded in the past, and esp. exactly what version/data was in that
> firmware file.

Firmware data is opaque to the firmware loader, as such details to
extract generic information about firmware details can only be done
by the driver, which could decode the firmware information. Many
drivers print these details themselves already, if they want it.

A generic interface to let us query *all* devices and currently loaded
firmware through the firmware loader would only be possible today for
firmware which requests (the default) caching of firmware upon
suspend/resume given that we keep the device / firmware name pair
around prior to suspend. For those devices it could be possible to
extend the firmware loader with a driver callback which can extract
firmware details in a generic codified way. To support *all* drivers
though, in a more clean way for this, a separate but similar list
could be kept which enables one to do this. Such items would be
torn down upon driver removal. But that would then be an opt-in
new mechanism.

Luis


Attachments:
(No filename) (1.45 kB)
signature.asc (849.00 B)
Download all attachments

2019-11-17 18:49:12

by Drew DeVault

[permalink] [raw]
Subject: Re: [PATCH v2] firmware loader: log path to loaded firmwares

I have a new patch prepared which moves my logging into
_request_firmware. Would you prefer I send this along or would you like
to take Robin's patch?

2019-11-17 23:49:05

by Robin H. Johnson

[permalink] [raw]
Subject: [PATCH v3] firmware: log name & outcome of loaded firmware

It's non-trivial to figure out names of firmware that was actually
loaded, add a debug statement at the end of _request_firmware that logs
the name & result of each firmware.

This is esp. valuable early in boot, before logging of UEVENT is
available.

v3:
- Log at dev_dbg level per maintainer.
- HOWTO: Enable at boot via kernel boot param
dyndbg="func _request_firmware +p"
- Credit to Drew DeVault for parallel creation and help promoting the
idea.

Alternate-Creation: Drew DeVault <[email protected]>
Signed-off-by: Robin H. Johnson <[email protected]>
---
drivers/base/firmware_loader/main.c | 7 +++++++
1 file changed, 7 insertions(+)

diff --git a/drivers/base/firmware_loader/main.c b/drivers/base/firmware_loader/main.c
index bf44c79beae9..84a879608ca4 100644
--- a/drivers/base/firmware_loader/main.c
+++ b/drivers/base/firmware_loader/main.c
@@ -791,6 +791,13 @@ _request_firmware(const struct firmware **firmware_p, const char *name,
fw = NULL;
}

+ /* Provide a consistent way to capture the result of trying to load any
+ * firmware. As a potential future improvement, this might include
+ * persistent state that firmware is loaded (or failed to load for some
+ * reason). See Message-ID: <[email protected]>
+ * for background */
+ dev_dbg(device, "%s %s ret=%d\n", __func__, name, ret);
+
*firmware_p = fw;
return ret;
}
--
2.24.0

2019-11-18 17:55:35

by Greg Kroah-Hartman

[permalink] [raw]
Subject: Re: [PATCH v3] firmware: log name & outcome of loaded firmware

On Sun, Nov 17, 2019 at 03:47:34PM -0800, Robin H. Johnson wrote:
> It's non-trivial to figure out names of firmware that was actually
> loaded, add a debug statement at the end of _request_firmware that logs
> the name & result of each firmware.
>
> This is esp. valuable early in boot, before logging of UEVENT is
> available.
>
> v3:
> - Log at dev_dbg level per maintainer.
> - HOWTO: Enable at boot via kernel boot param
> dyndbg="func _request_firmware +p"
> - Credit to Drew DeVault for parallel creation and help promoting the
> idea.

These "v3.." lines need to go below the --- line.

>
> Alternate-Creation: Drew DeVault <[email protected]>

Is that a valid tag? You can have co-developed-by (or something like
that, read the documentation for the real name), but I have never seen
this one before.

> Signed-off-by: Robin H. Johnson <[email protected]>
> ---
> drivers/base/firmware_loader/main.c | 7 +++++++
> 1 file changed, 7 insertions(+)
>
> diff --git a/drivers/base/firmware_loader/main.c b/drivers/base/firmware_loader/main.c
> index bf44c79beae9..84a879608ca4 100644
> --- a/drivers/base/firmware_loader/main.c
> +++ b/drivers/base/firmware_loader/main.c
> @@ -791,6 +791,13 @@ _request_firmware(const struct firmware **firmware_p, const char *name,
> fw = NULL;
> }
>
> + /* Provide a consistent way to capture the result of trying to load any
> + * firmware. As a potential future improvement, this might include
> + * persistent state that firmware is loaded (or failed to load for some
> + * reason). See Message-ID: <[email protected]>

Just provide a lore link with the message id if you really want this.

But really, this type of thing belongs in the changelog text, not in a
comment, right?

> + * for background */
> + dev_dbg(device, "%s %s ret=%d\n", __func__, name, ret);

That does not provide any real information as to what is going on, why
doesn't ftrace suffice for this?

thanks,

greg k-h