Re: [v5 01/12] struct device: Add function callback durable_name
Greg, >> > What text is changing? The format of of the prefix of dev_*() is well >> > known and has been stable for 15+ years now, right? What is difficult >> > in parsing it? >> >> Many of the storage layer messages are using printk, not dev_printk. > > Ok, then stop right there. Fix that up. Don't try to route around the > standard way of displaying log messages by creating a totally different > way of doing things. Couldn't agree more! -- Martin K. Petersen Oracle Linux Engineering
Re: [v5 01/12] struct device: Add function callback durable_name
On Wed, 7 Oct 2020, Tony Asleson wrote:
> The log information is not helpful without the information to correlate
> to the actual device.
Log messages that associate one entity with another can be generated
whenever such an association comes into existence, which is probably when
devices get probed.
E.g. a host:channel:target:lun identifier gets associated with a block
device name by the dev_printk() calls in sd_probe():
[3.60] sd 0:0:0:0: [sda] Attached SCSI disk
BTW, if you think of {"0:0:0:0","sda"} as a row in some normalized table
and squint a bit, this problem is not unlike the replication of database
tables over a message queue.
Re: [v5 01/12] struct device: Add function callback durable_name
On 10/7/20 10:10 PM, Tony Asleson wrote: On 10/1/20 6:48 AM, Greg Kroah-Hartman wrote: On Wed, Sep 30, 2020 at 09:35:52AM -0500, Tony Asleson wrote: On 9/30/20 2:38 AM, Greg Kroah-Hartman wrote: On Tue, Sep 29, 2020 at 05:04:32PM -0500, Tony Asleson wrote: I'm trying to figure out a way to positively identify which storage device an error belongs to over time. "over time" is not the kernel's responsibility. This comes up every 5 years or so. The kernel provides you, at runtime, a mapping between a hardware device and a "logical" device. It can provide information to userspace about this mapping, but once that device goes away, the kernel is free to reuse that logical device again. If you want to track what logical devices match up to what physical device, then do it in userspace, by parsing the log files. I don't understand why people think it's acceptable to ask user space to parse text that is subject to change. What text is changing? The format of of the prefix of dev_*() is well known and has been stable for 15+ years now, right? What is difficult in parsing it? Many of the storage layer messages are using printk, not dev_printk. So that would be the immediate angle of attack ... Thank you for supplying some feedback and asking questions. I've been asking for suggestions and would very much like to have a discussion on how this issue is best solved. I'm not attached to what I've provided. I'm just trying to get towards a solution. Again, solve this in userspace, you have the information there at runtime, why not use it? We usually don't have the needed information if you remove the expectation that user space should parse the human readable portion of the error message. I don't expect that userspace should have to parse any human readable portion, if they don't want to. But if you do want it to, it is pretty trivial to parse what you have today: scsi 2:0:0:0: Direct-Access Generic STORAGE DEVICE 1531 PQ: 0 ANSI: 6 If you really have a unique identifier, then great, parse it today: usb 4-1.3.1: Product: USB3.0 Card Reader usb 4-1.3.1: Manufacturer: Generic usb 4-1.3.1: SerialNumber: 1531 What's keeping that from working now? I believe these examples are using dev_printk. With dev_printk we don't need to parse the text, we can use the meta data. So it looks as most of your usecase would be solved by moving to dev_printk(). Why not work on that instead? I do presume this will have immediate benefits for everybody, and will have approval from everyone. Cheers, Hannes -- Dr. Hannes ReineckeKernel Storage Architect h...@suse.de +49 911 74053 688 SUSE Software Solutions GmbH, Maxfeldstr. 5, 90409 Nürnberg HRB 36809 (AG Nürnberg), Geschäftsführer: Felix Imendörffer
Re: [v5 01/12] struct device: Add function callback durable_name
On Wed, Oct 07, 2020 at 03:10:17PM -0500, Tony Asleson wrote: > On 10/1/20 6:48 AM, Greg Kroah-Hartman wrote: > > On Wed, Sep 30, 2020 at 09:35:52AM -0500, Tony Asleson wrote: > >> On 9/30/20 2:38 AM, Greg Kroah-Hartman wrote: > >>> On Tue, Sep 29, 2020 at 05:04:32PM -0500, Tony Asleson wrote: > I'm trying to figure out a way to positively identify which storage > device an error belongs to over time. > >>> > >>> "over time" is not the kernel's responsibility. > >>> > >>> This comes up every 5 years or so. The kernel provides you, at runtime, > >>> a mapping between a hardware device and a "logical" device. It can > >>> provide information to userspace about this mapping, but once that > >>> device goes away, the kernel is free to reuse that logical device again. > >>> > >>> If you want to track what logical devices match up to what physical > >>> device, then do it in userspace, by parsing the log files. > >> > >> I don't understand why people think it's acceptable to ask user space to > >> parse text that is subject to change. > > > > What text is changing? The format of of the prefix of dev_*() is well > > known and has been stable for 15+ years now, right? What is difficult > > in parsing it? > > Many of the storage layer messages are using printk, not dev_printk. Ok, then stop right there. Fix that up. Don't try to route around the standard way of displaying log messages by creating a totally different way of doing things. Just use the dev_*() calls, and all will be fine. Kernel log messages are not "ABI" in that they have to be preserved in any specific way, so adding a prefix to them as dev_*() does, will be fine. thanks, greg k-h
Re: [v5 01/12] struct device: Add function callback durable_name
On 10/1/20 6:48 AM, Greg Kroah-Hartman wrote:
> On Wed, Sep 30, 2020 at 09:35:52AM -0500, Tony Asleson wrote:
>> On 9/30/20 2:38 AM, Greg Kroah-Hartman wrote:
>>> On Tue, Sep 29, 2020 at 05:04:32PM -0500, Tony Asleson wrote:
I'm trying to figure out a way to positively identify which storage
device an error belongs to over time.
>>>
>>> "over time" is not the kernel's responsibility.
>>>
>>> This comes up every 5 years or so. The kernel provides you, at runtime,
>>> a mapping between a hardware device and a "logical" device. It can
>>> provide information to userspace about this mapping, but once that
>>> device goes away, the kernel is free to reuse that logical device again.
>>>
>>> If you want to track what logical devices match up to what physical
>>> device, then do it in userspace, by parsing the log files.
>>
>> I don't understand why people think it's acceptable to ask user space to
>> parse text that is subject to change.
>
> What text is changing? The format of of the prefix of dev_*() is well
> known and has been stable for 15+ years now, right? What is difficult
> in parsing it?
Many of the storage layer messages are using printk, not dev_printk.
Thank you for supplying some feedback and asking questions. I've been
asking for suggestions and would very much like to have a discussion on
how this issue is best solved. I'm not attached to what I've provided.
I'm just trying to get towards a solution.
>>>
>>> Again, solve this in userspace, you have the information there at
>>> runtime, why not use it?
>>
>> We usually don't have the needed information if you remove the
>> expectation that user space should parse the human readable portion of
>> the error message.
>
> I don't expect that userspace should have to parse any human readable
> portion, if they don't want to. But if you do want it to, it is pretty
> trivial to parse what you have today:
>
> scsi 2:0:0:0: Direct-Access Generic STORAGE DEVICE 1531 PQ: 0
> ANSI: 6
>
> If you really have a unique identifier, then great, parse it today:
>
> usb 4-1.3.1: Product: USB3.0 Card Reader
> usb 4-1.3.1: Manufacturer: Generic
> usb 4-1.3.1: SerialNumber: 1531
>
> What's keeping that from working now?
I believe these examples are using dev_printk. With dev_printk we don't
need to parse the text, we can use the meta data.
> In fact, I would argue that it does seem to work, as there are many
> commercial tools out there that seem to handle it just fine...
I'm trying to get something that's works for journalctl.
We've looked at user space quite a bit and there is an inherit race
condition with trying to fetch the unique hardware id for a message when
it gets emitted from the kernel as udev rules haven't even run (assuming
we even have the meta-data to make the association).
>>>
>>> But one moment later you do have the information, so you can properly
>>> correlate it, right?
>>
>> We could have the information if all the storage paths went through
>> dev_printk. Here is what we get today when we encounter a read error
>> which uses printk in the block layer:
>>
>> {
>> "_HOSTNAME" : "pn",
>> "_TRANSPORT" : "kernel",
>> "__MONOTONIC_TIMESTAMP" : "1806379233",
>> "SYSLOG_IDENTIFIER" : "kernel",
>> "_SOURCE_MONOTONIC_TIMESTAMP" : "1805611354",
>> "SYSLOG_FACILITY" : "0",
>> "MESSAGE" : "blk_update_request: critical medium error, dev
>> nvme0n1, sector 1 op 0x0:(READ) flags 0x80700 phys_seg 3 prio class 0",
>> "PRIORITY" : "3",
>> "_MACHINE_ID" : "3f31a0847cea4c95b7a9cec13d07deeb",
>> "__REALTIME_TIMESTAMP" : "1601471260802301",
>> "_BOOT_ID" : "b03ed610f21d46ab8243a495ba5a0058",
>> "__CURSOR" :
>> "s=a063a22bbb384da0b0412e8f652deabb;i=23c2;b=b03ed610f21d46ab8243a495ba5a0058;m=6bab28e1;t=5b087959e3cfd;x=20528862f8f765c9"
>> }
>
> Ok, messy stuff, don't do that :)
>
>> Unless you parse the message text you cannot make the association. If
>> the same message was changed to dev_printk we would get:
>>
>>
>> {
>> "__REALTIME_TIMESTAMP" : "1589401901093443",
>> "__CURSOR" :
>> "s=caac9703b34a48fd92f7875adae55a2f;i=1c713;b=e2ae14a9def345aa803a13648b95429c;m=7d25b4f;t=5a58d77b85243;x=b034c2d3fb853870",
>> "SYSLOG_IDENTIFIER" : "kernel",
>> "_KERNEL_DEVICE" : "b259:917504",
>> "__MONOTONIC_TIMESTAMP" : "131226447",
>> "_UDEV_SYSNAME" : "nvme0n1",
>> "PRIORITY" : "3",
>> "_KERNEL_SUBSYSTEM" : "block",
>> "_SOURCE_MONOTONIC_TIMESTAMP" : "130941917",
>> "_TRANSPORT" : "kernel",
>> "_MACHINE_ID" : "3f31a0847cea4c95b7a9cec13d07deeb",
>> "_HOSTNAME" : "pn",
>> "SYSLOG_FACILITY" : "0",
>> "_BOOT_ID" : "e2ae14a9def345aa803a13648b95429c",
>> "_UDEV_DEVLINK" : [
>> "/dev/disk/by-uuid/22fc262a-d621-452a-a951-7761d9fcf0dc",
>>
