* Flood of logitech-hidpp-device messages in v6.7
@ 2024-01-09 11:45 Oleksandr Natalenko
2024-01-09 11:58 ` Hans de Goede
0 siblings, 1 reply; 9+ messages in thread
From: Oleksandr Natalenko @ 2024-01-09 11:45 UTC (permalink / raw)
To: linux-kernel
Cc: linux-input, Filipe Laíns, Bastien Nocera, Jiri Kosina,
Benjamin Tissoires, Hans de Goede
[-- Attachment #1: Type: text/plain, Size: 2529 bytes --]
Hello Hans et al.
Starting from v6.7 release I get the following messages repeating in `dmesg` regularly:
```
Jan 09 10:05:06 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected
Jan 09 10:07:15 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected
Jan 09 10:16:51 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected.
Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected.
Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected.
Jan 09 10:36:31 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected
Jan 09 10:37:07 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected.
Jan 09 10:46:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected
Jan 09 10:48:23 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected
Jan 09 11:12:27 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected.
Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected.
Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected.
Jan 09 11:38:32 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected
Jan 09 11:43:32 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected
Jan 09 11:45:10 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected.
Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected.
Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected.
Jan 09 12:31:48 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected
Jan 09 12:33:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected.
```
I've got the following hardware:
* Bus 006 Device 004: ID 046d:c52b Logitech, Inc. Unifying Receiver
* Logitech MX Keys
* Logitech M510v2
With v6.6 I do not get those messages.
I think this is related to 680ee411a98e ("HID: logitech-hidpp: Fix connect event race").
My speculation is that some of the devices enter powersaving state after being idle for some time (5 mins?), and then wake up and reconnect once I touch either keyboard or mouse. I should highlight that everything works just fine, it is the flood of messages that worries me.
Is it expected?
Thank you.
--
Oleksandr Natalenko (post-factum)
[-- Attachment #2: This is a digitally signed message part. --]
[-- Type: application/pgp-signature, Size: 833 bytes --]
^ permalink raw reply [flat|nested] 9+ messages in thread* Re: Flood of logitech-hidpp-device messages in v6.7 2024-01-09 11:45 Flood of logitech-hidpp-device messages in v6.7 Oleksandr Natalenko @ 2024-01-09 11:58 ` Hans de Goede 2024-01-09 14:18 ` Benjamin Tissoires ` (2 more replies) 0 siblings, 3 replies; 9+ messages in thread From: Hans de Goede @ 2024-01-09 11:58 UTC (permalink / raw) To: Oleksandr Natalenko, linux-kernel Cc: linux-input, Filipe Laíns, Bastien Nocera, Jiri Kosina, Benjamin Tissoires Hi Oleksandr, On 1/9/24 12:45, Oleksandr Natalenko wrote: > Hello Hans et al. > > Starting from v6.7 release I get the following messages repeating in `dmesg` regularly: > > ``` > Jan 09 10:05:06 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > Jan 09 10:07:15 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected > Jan 09 10:16:51 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > Jan 09 10:36:31 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > Jan 09 10:37:07 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > Jan 09 10:46:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > Jan 09 10:48:23 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected > Jan 09 11:12:27 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > Jan 09 11:38:32 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > Jan 09 11:43:32 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected > Jan 09 11:45:10 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > Jan 09 12:31:48 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > Jan 09 12:33:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > ``` > > I've got the following hardware: > > * Bus 006 Device 004: ID 046d:c52b Logitech, Inc. Unifying Receiver > * Logitech MX Keys > * Logitech M510v2 > > With v6.6 I do not get those messages. > > I think this is related to 680ee411a98e ("HID: logitech-hidpp: Fix connect event race"). > > My speculation is that some of the devices enter powersaving state after being idle for some time (5 mins?), and then wake up and reconnect once I touch either keyboard or mouse. I should highlight that everything works just fine, it is the flood of messages that worries me. > > Is it expected? Yes this is expected, looking at your logs I see about 10 messages per hour which IMHO is not that bad. I guess we could change things to track we have logged the connect message once and if yes then log future connect messages (and all disconnect messages) at debug level. Jiri, Benjamin, do you have any opinion on this ? Regards, Hans ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: Flood of logitech-hidpp-device messages in v6.7 2024-01-09 11:58 ` Hans de Goede @ 2024-01-09 14:18 ` Benjamin Tissoires 2024-01-17 19:01 ` Jiri Kosina 2024-01-29 15:58 ` Oleksandr Natalenko 2 siblings, 0 replies; 9+ messages in thread From: Benjamin Tissoires @ 2024-01-09 14:18 UTC (permalink / raw) To: Hans de Goede Cc: Oleksandr Natalenko, linux-kernel, linux-input, Filipe Laíns, Bastien Nocera, Jiri Kosina On Tue, Jan 9, 2024 at 12:58 PM Hans de Goede <hdegoede@redhat.com> wrote: > > Hi Oleksandr, > > On 1/9/24 12:45, Oleksandr Natalenko wrote: > > Hello Hans et al. > > > > Starting from v6.7 release I get the following messages repeating in `dmesg` regularly: > > > > ``` > > Jan 09 10:05:06 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > > Jan 09 10:07:15 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected > > Jan 09 10:16:51 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > > Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 10:36:31 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > > Jan 09 10:37:07 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > > Jan 09 10:46:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > > Jan 09 10:48:23 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected > > Jan 09 11:12:27 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > > Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 11:38:32 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > > Jan 09 11:43:32 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected > > Jan 09 11:45:10 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > > Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 12:31:48 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > > Jan 09 12:33:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > > ``` > > > > I've got the following hardware: > > > > * Bus 006 Device 004: ID 046d:c52b Logitech, Inc. Unifying Receiver > > * Logitech MX Keys > > * Logitech M510v2 > > > > With v6.6 I do not get those messages. > > > > I think this is related to 680ee411a98e ("HID: logitech-hidpp: Fix connect event race"). > > > > My speculation is that some of the devices enter powersaving state after being idle for some time (5 mins?), and then wake up and reconnect once I touch either keyboard or mouse. I should highlight that everything works just fine, it is the flood of messages that worries me. > > > > Is it expected? > > Yes this is expected, looking at your logs I see about 10 messages per > hour which IMHO is not that bad. > > I guess we could change things to track we have logged the connect > message once and if yes then log future connect messages (and all > disconnect messages) at debug level. Sounds reasonable to me. Cheers, Benjamin > > > Jiri, Benjamin, do you have any opinion on this ? > > Regards, > > Hans > > > ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: Flood of logitech-hidpp-device messages in v6.7 2024-01-09 11:58 ` Hans de Goede 2024-01-09 14:18 ` Benjamin Tissoires @ 2024-01-17 19:01 ` Jiri Kosina 2024-01-29 11:10 ` Hans de Goede 2024-01-29 15:58 ` Oleksandr Natalenko 2 siblings, 1 reply; 9+ messages in thread From: Jiri Kosina @ 2024-01-17 19:01 UTC (permalink / raw) To: Hans de Goede Cc: Oleksandr Natalenko, linux-kernel, linux-input, Filipe Laíns, Bastien Nocera, Benjamin Tissoires On Tue, 9 Jan 2024, Hans de Goede wrote: > > Jan 09 10:05:06 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > > Jan 09 10:07:15 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected > > Jan 09 10:16:51 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > > Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 10:36:31 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > > Jan 09 10:37:07 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > > Jan 09 10:46:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > > Jan 09 10:48:23 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected > > Jan 09 11:12:27 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > > Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 11:38:32 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > > Jan 09 11:43:32 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected > > Jan 09 11:45:10 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > > Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 12:31:48 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > > Jan 09 12:33:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > > ``` > > > > I've got the following hardware: > > > > * Bus 006 Device 004: ID 046d:c52b Logitech, Inc. Unifying Receiver > > * Logitech MX Keys > > * Logitech M510v2 > > > > With v6.6 I do not get those messages. > > > > I think this is related to 680ee411a98e ("HID: logitech-hidpp: Fix connect event race"). > > > > My speculation is that some of the devices enter powersaving state after being idle for some time (5 mins?), and then wake up and reconnect once I touch either keyboard or mouse. I should highlight that everything works just fine, it is the flood of messages that worries me. > > > > Is it expected? > > Yes this is expected, looking at your logs I see about 10 messages per > hour which IMHO is not that bad. > > I guess we could change things to track we have logged the connect > message once and if yes then log future connect messages (and all > disconnect messages) at debug level. > > Jiri, Benjamin, do you have any opinion on this ? Works for me, thanks. Do you plan to submit the patch implementing this? -- Jiri Kosina SUSE Labs ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: Flood of logitech-hidpp-device messages in v6.7 2024-01-17 19:01 ` Jiri Kosina @ 2024-01-29 11:10 ` Hans de Goede 0 siblings, 0 replies; 9+ messages in thread From: Hans de Goede @ 2024-01-29 11:10 UTC (permalink / raw) To: Jiri Kosina Cc: Oleksandr Natalenko, linux-kernel, linux-input, Filipe Laíns, Bastien Nocera, Benjamin Tissoires Hi Jiri, On 1/17/24 20:01, Jiri Kosina wrote: > On Tue, 9 Jan 2024, Hans de Goede wrote: > >>> Jan 09 10:05:06 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected >>> Jan 09 10:07:15 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected >>> Jan 09 10:16:51 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. >>> Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>> Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>> Jan 09 10:36:31 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected >>> Jan 09 10:37:07 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. >>> Jan 09 10:46:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected >>> Jan 09 10:48:23 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected >>> Jan 09 11:12:27 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. >>> Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>> Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>> Jan 09 11:38:32 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected >>> Jan 09 11:43:32 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected >>> Jan 09 11:45:10 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. >>> Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>> Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>> Jan 09 12:31:48 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected >>> Jan 09 12:33:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. >>> ``` >>> >>> I've got the following hardware: >>> >>> * Bus 006 Device 004: ID 046d:c52b Logitech, Inc. Unifying Receiver >>> * Logitech MX Keys >>> * Logitech M510v2 >>> >>> With v6.6 I do not get those messages. >>> >>> I think this is related to 680ee411a98e ("HID: logitech-hidpp: Fix connect event race"). >>> >>> My speculation is that some of the devices enter powersaving state after being idle for some time (5 mins?), and then wake up and reconnect once I touch either keyboard or mouse. I should highlight that everything works just fine, it is the flood of messages that worries me. >>> >>> Is it expected? >> >> Yes this is expected, looking at your logs I see about 10 messages per >> hour which IMHO is not that bad. >> >> I guess we could change things to track we have logged the connect >> message once and if yes then log future connect messages (and all >> disconnect messages) at debug level. >> >> Jiri, Benjamin, do you have any opinion on this ? > > Works for me, thanks. Do you plan to submit the patch implementing this? I was planning too, but I'm a bit swamped atm. I would not mind someone else implementing this suggestion and I would be happy to review and test. Regards, Hans ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: Flood of logitech-hidpp-device messages in v6.7 2024-01-09 11:58 ` Hans de Goede 2024-01-09 14:18 ` Benjamin Tissoires 2024-01-17 19:01 ` Jiri Kosina @ 2024-01-29 15:58 ` Oleksandr Natalenko 2024-01-29 16:08 ` Hans de Goede 2 siblings, 1 reply; 9+ messages in thread From: Oleksandr Natalenko @ 2024-01-29 15:58 UTC (permalink / raw) To: linux-kernel, Hans de Goede Cc: linux-input, Filipe Laíns, Bastien Nocera, Jiri Kosina, Benjamin Tissoires [-- Attachment #1: Type: text/plain, Size: 3436 bytes --] Hello. On úterý 9. ledna 2024 12:58:10 CET Hans de Goede wrote: > Hi Oleksandr, > > On 1/9/24 12:45, Oleksandr Natalenko wrote: > > Hello Hans et al. > > > > Starting from v6.7 release I get the following messages repeating in `dmesg` regularly: > > > > ``` > > Jan 09 10:05:06 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > > Jan 09 10:07:15 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected > > Jan 09 10:16:51 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > > Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 10:36:31 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > > Jan 09 10:37:07 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > > Jan 09 10:46:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > > Jan 09 10:48:23 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected > > Jan 09 11:12:27 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > > Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 11:38:32 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > > Jan 09 11:43:32 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected > > Jan 09 11:45:10 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > > Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > > Jan 09 12:31:48 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > > Jan 09 12:33:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > > ``` > > > > I've got the following hardware: > > > > * Bus 006 Device 004: ID 046d:c52b Logitech, Inc. Unifying Receiver > > * Logitech MX Keys > > * Logitech M510v2 > > > > With v6.6 I do not get those messages. > > > > I think this is related to 680ee411a98e ("HID: logitech-hidpp: Fix connect event race"). > > > > My speculation is that some of the devices enter powersaving state after being idle for some time (5 mins?), and then wake up and reconnect once I touch either keyboard or mouse. I should highlight that everything works just fine, it is the flood of messages that worries me. > > > > Is it expected? > > Yes this is expected, looking at your logs I see about 10 messages per > hour which IMHO is not that bad. > > I guess we could change things to track we have logged the connect > message once and if yes then log future connect messages (and all > disconnect messages) at debug level. How granular such a tracking should be? Per-`struct hidpp_device`? Should there be something like `hid_info_once_then_dbg()` macro, or open-code it in each place instead? Thanks. > Jiri, Benjamin, do you have any opinion on this ? > > Regards, > > Hans > > > > -- Oleksandr Natalenko (post-factum) [-- Attachment #2: This is a digitally signed message part. --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: Flood of logitech-hidpp-device messages in v6.7 2024-01-29 15:58 ` Oleksandr Natalenko @ 2024-01-29 16:08 ` Hans de Goede 2024-01-29 16:19 ` Oleksandr Natalenko 0 siblings, 1 reply; 9+ messages in thread From: Hans de Goede @ 2024-01-29 16:08 UTC (permalink / raw) To: Oleksandr Natalenko, linux-kernel Cc: linux-input, Filipe Laíns, Bastien Nocera, Jiri Kosina, Benjamin Tissoires Hi, On 1/29/24 16:58, Oleksandr Natalenko wrote: > Hello. > > On úterý 9. ledna 2024 12:58:10 CET Hans de Goede wrote: >> Hi Oleksandr, >> >> On 1/9/24 12:45, Oleksandr Natalenko wrote: >>> Hello Hans et al. >>> >>> Starting from v6.7 release I get the following messages repeating in `dmesg` regularly: >>> >>> ``` >>> Jan 09 10:05:06 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected >>> Jan 09 10:07:15 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected >>> Jan 09 10:16:51 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. >>> Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>> Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>> Jan 09 10:36:31 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected >>> Jan 09 10:37:07 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. >>> Jan 09 10:46:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected >>> Jan 09 10:48:23 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected >>> Jan 09 11:12:27 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. >>> Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>> Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>> Jan 09 11:38:32 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected >>> Jan 09 11:43:32 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected >>> Jan 09 11:45:10 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. >>> Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>> Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>> Jan 09 12:31:48 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected >>> Jan 09 12:33:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. >>> ``` >>> >>> I've got the following hardware: >>> >>> * Bus 006 Device 004: ID 046d:c52b Logitech, Inc. Unifying Receiver >>> * Logitech MX Keys >>> * Logitech M510v2 >>> >>> With v6.6 I do not get those messages. >>> >>> I think this is related to 680ee411a98e ("HID: logitech-hidpp: Fix connect event race"). >>> >>> My speculation is that some of the devices enter powersaving state after being idle for some time (5 mins?), and then wake up and reconnect once I touch either keyboard or mouse. I should highlight that everything works just fine, it is the flood of messages that worries me. >>> >>> Is it expected? >> >> Yes this is expected, looking at your logs I see about 10 messages per >> hour which IMHO is not that bad. >> >> I guess we could change things to track we have logged the connect >> message once and if yes then log future connect messages (and all >> disconnect messages) at debug level. > > How granular such a tracking should be? Per-`struct hidpp_device`? Yes per struct hidpp_device we want to log the connect message once per device since it gives info which might be useful for troubleshooting. > Should there be something like `hid_info_once_then_dbg()` macro, or open-code it in each place instead? Since we want something like e.g. a "first_connect" (initialized to true if you use that name) flag per struct hidpp_device this needs to be open coded. Regards, Hans ^ permalink raw reply [flat|nested] 9+ messages in thread
* Re: Flood of logitech-hidpp-device messages in v6.7 2024-01-29 16:08 ` Hans de Goede @ 2024-01-29 16:19 ` Oleksandr Natalenko 2024-01-29 16:31 ` Hans de Goede 0 siblings, 1 reply; 9+ messages in thread From: Oleksandr Natalenko @ 2024-01-29 16:19 UTC (permalink / raw) To: linux-kernel, Hans de Goede Cc: linux-input, Filipe Laíns, Bastien Nocera, Jiri Kosina, Benjamin Tissoires [-- Attachment #1: Type: text/plain, Size: 5603 bytes --] On pondělí 29. ledna 2024 17:08:56 CET Hans de Goede wrote: > Hi, > > On 1/29/24 16:58, Oleksandr Natalenko wrote: > > Hello. > > > > On úterý 9. ledna 2024 12:58:10 CET Hans de Goede wrote: > >> Hi Oleksandr, > >> > >> On 1/9/24 12:45, Oleksandr Natalenko wrote: > >>> Hello Hans et al. > >>> > >>> Starting from v6.7 release I get the following messages repeating in `dmesg` regularly: > >>> > >>> ``` > >>> Jan 09 10:05:06 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > >>> Jan 09 10:07:15 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected > >>> Jan 09 10:16:51 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > >>> Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > >>> Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > >>> Jan 09 10:36:31 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > >>> Jan 09 10:37:07 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > >>> Jan 09 10:46:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > >>> Jan 09 10:48:23 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected > >>> Jan 09 11:12:27 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > >>> Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > >>> Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > >>> Jan 09 11:38:32 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > >>> Jan 09 11:43:32 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected > >>> Jan 09 11:45:10 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > >>> Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > >>> Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. > >>> Jan 09 12:31:48 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected > >>> Jan 09 12:33:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. > >>> ``` > >>> > >>> I've got the following hardware: > >>> > >>> * Bus 006 Device 004: ID 046d:c52b Logitech, Inc. Unifying Receiver > >>> * Logitech MX Keys > >>> * Logitech M510v2 > >>> > >>> With v6.6 I do not get those messages. > >>> > >>> I think this is related to 680ee411a98e ("HID: logitech-hidpp: Fix connect event race"). > >>> > >>> My speculation is that some of the devices enter powersaving state after being idle for some time (5 mins?), and then wake up and reconnect once I touch either keyboard or mouse. I should highlight that everything works just fine, it is the flood of messages that worries me. > >>> > >>> Is it expected? > >> > >> Yes this is expected, looking at your logs I see about 10 messages per > >> hour which IMHO is not that bad. > >> > >> I guess we could change things to track we have logged the connect > >> message once and if yes then log future connect messages (and all > >> disconnect messages) at debug level. > > > > How granular such a tracking should be? Per-`struct hidpp_device`? > > Yes per struct hidpp_device we want to log the connect message once > per device since it gives info which might be useful for troubleshooting. > > > Should there be something like `hid_info_once_then_dbg()` macro, or open-code it in each place instead? > > Since we want something like e.g. a "first_connect" (initialized > to true if you use that name) flag per struct hidpp_device this needs > to be open coded. OK, would something like this make sense (not tested)? ``` diff --git a/drivers/hid/hid-logitech-hidpp.c b/drivers/hid/hid-logitech-hidpp.c index 6ef0c88e3e60a..a9899709d6b74 100644 --- a/drivers/hid/hid-logitech-hidpp.c +++ b/drivers/hid/hid-logitech-hidpp.c @@ -203,6 +203,9 @@ struct hidpp_device { struct hidpp_scroll_counter vertical_wheel_counter; u8 wireless_feature_index; + + bool once_connected; + bool once_disconnected; }; /* HID++ 1.0 error codes */ @@ -988,8 +991,13 @@ static int hidpp_root_get_protocol_version(struct hidpp_device *hidpp) hidpp->protocol_minor = response.rap.params[1]; print_version: - hid_info(hidpp->hid_dev, "HID++ %u.%u device connected.\n", - hidpp->protocol_major, hidpp->protocol_minor); + if (!hidpp->once_connected) { + hid_info(hidpp->hid_dev, "HID++ %u.%u device connected.\n", + hidpp->protocol_major, hidpp->protocol_minor); + hidpp->once_connected = true; + } else + hid_dbg(hidpp->hid_dev, "HID++ %u.%u device connected.\n", + hidpp->protocol_major, hidpp->protocol_minor); return 0; } @@ -4184,7 +4192,11 @@ static void hidpp_connect_event(struct work_struct *work) /* Get device version to check if it is connected */ ret = hidpp_root_get_protocol_version(hidpp); if (ret) { - hid_info(hidpp->hid_dev, "Disconnected\n"); + if (!hidpp->once_disconnected) { + hid_info(hidpp->hid_dev, "Disconnected\n"); + hidpp->once_disconnected = true; + } else + hid_dbg(hidpp->hid_dev, "Disconnected\n"); if (hidpp->battery.ps) { hidpp->battery.online = false; hidpp->battery.status = POWER_SUPPLY_STATUS_UNKNOWN; ``` > > Regards, > > Hans > > > > > -- Oleksandr Natalenko (post-factum) [-- Attachment #2: This is a digitally signed message part. --] [-- Type: application/pgp-signature, Size: 833 bytes --] ^ permalink raw reply related [flat|nested] 9+ messages in thread
* Re: Flood of logitech-hidpp-device messages in v6.7 2024-01-29 16:19 ` Oleksandr Natalenko @ 2024-01-29 16:31 ` Hans de Goede 0 siblings, 0 replies; 9+ messages in thread From: Hans de Goede @ 2024-01-29 16:31 UTC (permalink / raw) To: Oleksandr Natalenko, linux-kernel Cc: linux-input, Filipe Laíns, Bastien Nocera, Jiri Kosina, Benjamin Tissoires Hi Oleksandr, On 1/29/24 17:19, Oleksandr Natalenko wrote: > On pondělí 29. ledna 2024 17:08:56 CET Hans de Goede wrote: >> Hi, >> >> On 1/29/24 16:58, Oleksandr Natalenko wrote: >>> Hello. >>> >>> On úterý 9. ledna 2024 12:58:10 CET Hans de Goede wrote: >>>> Hi Oleksandr, >>>> >>>> On 1/9/24 12:45, Oleksandr Natalenko wrote: >>>>> Hello Hans et al. >>>>> >>>>> Starting from v6.7 release I get the following messages repeating in `dmesg` regularly: >>>>> >>>>> ``` >>>>> Jan 09 10:05:06 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected >>>>> Jan 09 10:07:15 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected >>>>> Jan 09 10:16:51 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. >>>>> Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>>>> Jan 09 10:16:55 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>>>> Jan 09 10:36:31 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected >>>>> Jan 09 10:37:07 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. >>>>> Jan 09 10:46:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected >>>>> Jan 09 10:48:23 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected >>>>> Jan 09 11:12:27 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. >>>>> Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>>>> Jan 09 11:12:47 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>>>> Jan 09 11:38:32 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected >>>>> Jan 09 11:43:32 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: Disconnected >>>>> Jan 09 11:45:10 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. >>>>> Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>>>> Jan 09 11:45:11 spock kernel: logitech-hidpp-device 0003:046D:408A.0005: HID++ 4.5 device connected. >>>>> Jan 09 12:31:48 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: Disconnected >>>>> Jan 09 12:33:21 spock kernel: logitech-hidpp-device 0003:046D:4051.0006: HID++ 4.5 device connected. >>>>> ``` >>>>> >>>>> I've got the following hardware: >>>>> >>>>> * Bus 006 Device 004: ID 046d:c52b Logitech, Inc. Unifying Receiver >>>>> * Logitech MX Keys >>>>> * Logitech M510v2 >>>>> >>>>> With v6.6 I do not get those messages. >>>>> >>>>> I think this is related to 680ee411a98e ("HID: logitech-hidpp: Fix connect event race"). >>>>> >>>>> My speculation is that some of the devices enter powersaving state after being idle for some time (5 mins?), and then wake up and reconnect once I touch either keyboard or mouse. I should highlight that everything works just fine, it is the flood of messages that worries me. >>>>> >>>>> Is it expected? >>>> >>>> Yes this is expected, looking at your logs I see about 10 messages per >>>> hour which IMHO is not that bad. >>>> >>>> I guess we could change things to track we have logged the connect >>>> message once and if yes then log future connect messages (and all >>>> disconnect messages) at debug level. >>> >>> How granular such a tracking should be? Per-`struct hidpp_device`? >> >> Yes per struct hidpp_device we want to log the connect message once >> per device since it gives info which might be useful for troubleshooting. >> >>> Should there be something like `hid_info_once_then_dbg()` macro, or open-code it in each place instead? >> >> Since we want something like e.g. a "first_connect" (initialized >> to true if you use that name) flag per struct hidpp_device this needs >> to be open coded. > > OK, would something like this make sense (not tested)? Yes, thank you. I would call once_connected connected_once and you can drop the disconnected flag and just always log disconnect messages at the dbg level. Regards, Hans > > ``` > diff --git a/drivers/hid/hid-logitech-hidpp.c b/drivers/hid/hid-logitech-hidpp.c > index 6ef0c88e3e60a..a9899709d6b74 100644 > --- a/drivers/hid/hid-logitech-hidpp.c > +++ b/drivers/hid/hid-logitech-hidpp.c > @@ -203,6 +203,9 @@ struct hidpp_device { > struct hidpp_scroll_counter vertical_wheel_counter; > > u8 wireless_feature_index; > + > + bool once_connected; > + bool once_disconnected; > }; > > /* HID++ 1.0 error codes */ > @@ -988,8 +991,13 @@ static int hidpp_root_get_protocol_version(struct hidpp_device *hidpp) > hidpp->protocol_minor = response.rap.params[1]; > > print_version: > - hid_info(hidpp->hid_dev, "HID++ %u.%u device connected.\n", > - hidpp->protocol_major, hidpp->protocol_minor); > + if (!hidpp->once_connected) { > + hid_info(hidpp->hid_dev, "HID++ %u.%u device connected.\n", > + hidpp->protocol_major, hidpp->protocol_minor); > + hidpp->once_connected = true; > + } else > + hid_dbg(hidpp->hid_dev, "HID++ %u.%u device connected.\n", > + hidpp->protocol_major, hidpp->protocol_minor); > return 0; > } > > @@ -4184,7 +4192,11 @@ static void hidpp_connect_event(struct work_struct *work) > /* Get device version to check if it is connected */ > ret = hidpp_root_get_protocol_version(hidpp); > if (ret) { > - hid_info(hidpp->hid_dev, "Disconnected\n"); > + if (!hidpp->once_disconnected) { > + hid_info(hidpp->hid_dev, "Disconnected\n"); > + hidpp->once_disconnected = true; > + } else > + hid_dbg(hidpp->hid_dev, "Disconnected\n"); > if (hidpp->battery.ps) { > hidpp->battery.online = false; > hidpp->battery.status = POWER_SUPPLY_STATUS_UNKNOWN; > ``` > >> >> Regards, >> >> Hans >> >> >> >> >> > > ^ permalink raw reply [flat|nested] 9+ messages in thread
end of thread, other threads:[~2024-01-29 16:32 UTC | newest] Thread overview: 9+ messages (download: mbox.gz / follow: Atom feed) -- links below jump to the message on this page -- 2024-01-09 11:45 Flood of logitech-hidpp-device messages in v6.7 Oleksandr Natalenko 2024-01-09 11:58 ` Hans de Goede 2024-01-09 14:18 ` Benjamin Tissoires 2024-01-17 19:01 ` Jiri Kosina 2024-01-29 11:10 ` Hans de Goede 2024-01-29 15:58 ` Oleksandr Natalenko 2024-01-29 16:08 ` Hans de Goede 2024-01-29 16:19 ` Oleksandr Natalenko 2024-01-29 16:31 ` Hans de Goede
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox; as well as URLs for NNTP newsgroup(s).