Re: Flood of logitech-hidpp-device messages in v6.7

From: Hans de Goede <hdegoede@redhat.com>
To: Jiri Kosina <jikos@kernel.org>
Cc: "Oleksandr Natalenko" <oleksandr@natalenko.name>,
	linux-kernel@vger.kernel.org, linux-input@vger.kernel.org,
	"Filipe Laíns" <lains@riseup.net>,
	"Bastien Nocera" <hadess@hadess.net>,
	"Benjamin Tissoires" <benjamin.tissoires@redhat.com>
Subject: Re: Flood of logitech-hidpp-device messages in v6.7
Date: Mon, 29 Jan 2024 12:10:37 +0100	[thread overview]
Message-ID: <4c68a68f-5fc6-4906-b958-4e2bd8fcd25a@redhat.com> (raw)
In-Reply-To: <nycvar.YFH.7.76.2401172001530.29548@cbobk.fhfr.pm>

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