hid-sensor-hub spamming dmesg in 4.20 - 5.3

Bug #1818547 reported by Fmstrat on 2019-03-04
86
This bug affects 16 people
Affects Status Importance Assigned to Milestone
Linux
Confirmed
High
linux (Ubuntu)
Undecided
Unassigned
Disco
Undecided
Unassigned

Bug Description

=== SRU Justification ===
[Impact]
[ 406.165461] hid-sensor-hub 001F:8086:22D8.0002: hid_field_extract() called with n (192) > 32! (kworker/5:1)

[Fix]
Let HID core allow longer input report length.

[Test]
User confirmed the fix works.

[Regression Potential]
Low. Longer input report length is now considered valid, shorter input
report length doesn't get touched.

=== Original Bug Report ===

Dmesg is a constant barrage of the same error:
```
[ 406.165461] hid-sensor-hub 001F:8086:22D8.0002: hid_field_extract() called with n (192) > 32! (kworker/5:1)
```

This does not occur in 4.19 but does occur in all mainline 4.20 releases including 4.20.13 (linux-image-unsigned-4.20.13-042013). Tested with both Ubuntu's included libinput 1.10 and an updated libinput 1.12.

Hardware (from lspci) includes a synaptic touchpad. Having the xorg synaptic driver installed makes no difference.

CVE References

Fmstrat (fmstrat) wrote :
Fmstrat (fmstrat) wrote :
Fmstrat (fmstrat) wrote :

This change was made by a bot.

Changed in linux (Ubuntu):
status: New → Confirmed

Just tested in 5.0 kernel, same output. Please see second dmesg.log for 5.0 output.

Kai-Heng Feng (kaihengfeng) wrote :

Would it be possible for you to do a kernel bisection?

First, find the last good -rc kernel and the first bad -rc kernel from http://kernel.ubuntu.com/~kernel-ppa/mainline/

Then,
$ sudo apt build-dep linux
$ git clone git://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git
$ cd linux
$ git bisect start
$ git bisect good $(the good version you found)
$ git bisect bad $(the bad version found)
$ make localmodconfig
$ make -j`nproc` deb-pkg
Install the newly built kernel, then reboot with it.
If the issue still happens,
$ git bisect bad
Otherwise,
$ git bisect good
Repeat to "make -j`nproc` deb-pkg" until you find the commit that causes the regression.

Fmstrat (fmstrat) wrote :

How do I find the commit for the bisect good/bad command? The last good version was 4.19.27, the first bad version was 4.20.0.

Fmstrat (fmstrat) wrote :

I think I figured it out, I can't use 4.19.27, but have to use 4.19. However:

# git bisect good v4.19
# git bisect bad v4.20
Some good revs are not ancestors of the bad rev.
git bisect cannot work properly in this case.
Maybe you mistook good and bad revs?
#

Is it safe to continue?

Kai-Heng Feng (kaihengfeng) wrote :

It's better to find the last good v4.20-rc* and first bad v4.20-rc*, then start a bisection between them.

Fmstrat (fmstrat) wrote :

It happens in 4.20-rc1, so should I try to bisect between 4.19 and 4.20-rc1?

Fmstrat (fmstrat) wrote :

It happens in 4.20-rc1, so should I try to bisect between 4.19 and 4.20-rc1?

I gave that a shot, but after labeling the first try "bad", the next make gave me:

...
dpkg-source: warning: no source format specified in debian/source/format, see dpkg-source(1)
dpkg-source: info: using source format '1.0'
dpkg-source: warning: source directory 'linux' is not <sourcepackage>-<upstreamversion> 'linux-4.19.0-rc8+-4.19.0-rc8+'
dpkg-source: warning: .orig directory name linux.orig is not <package>-<upstreamversion> (wanted linux-4.19.0-rc8+-4.19.0-rc8+.orig)
dpkg-source: info: building linux-4.19.0-rc8+ using existing linux-4.19.0-rc8+_4.19.0-rc8+.orig.tar.gz
dpkg-source: info: building linux-4.19.0-rc8+ in linux-4.19.0-rc8+_4.19.0-rc8+-1.diff.gz
dpkg-source: error: cannot represent change to vmlinux-gdb.py:
dpkg-source: error: new version is symlink to /opt/kernel/linux/scripts/gdb/vmlinux-gdb.py
dpkg-source: error: old version is nonexistent
dpkg-source: warning: ignoring deletion of file .scmversion, use --include-removal to override
dpkg-source: warning: the diff modifies the following upstream files:
...
dpkg-source: info: use the '3.0 (quilt)' format to have separate and documented changes to upstream files, see dpkg-source(1)
dpkg-source: error: unrepresentable changes to source
dpkg-buildpackage: error: dpkg-source -i.git -b linux subprocess returned exit status 1
scripts/package/Makefile:71: recipe for target 'deb-pkg' failed
make[1]: *** [deb-pkg] Error 1
Makefile:1357: recipe for target 'deb-pkg' failed
make: *** [deb-pkg] Error 2

So I'm not sure where to go from here.

Fmstrat (fmstrat) wrote :

As a note, the issue shows up in the first build attempt which was "linux-image-4.19.0+_4.19.0+-1_amd64.deb". This seems like before the 4.19.27 I did not see the issue in.

Fmstrat (fmstrat) wrote :

I've just tried official 4.19.0, and no issue there. So I'm not sure what's going on.

Kai-Heng Feng (kaihengfeng) wrote :

The instruction uses deb because it's easier to remove.

We can skip building the deb though.
Use "make -j`nproc` && make -j`nproc` modules && sudo make modules_install && sudo make install` instead.

When the bisection is done, the "artifacts" are in /boot/, /lib/modules/ and /var/lib/initramfs-tools/. Remove files in those places.

Mayur Virkar (mayurvirkar) wrote :

I may be able to shed some light on this issue.
I am facing the same problem as described by the FMstrat, but in my case, its caused by Accelerometer orientation which of course doesn't work.
I am on kernel 5.0 mainline and I am still facing the same problem.

Fmstrat (fmstrat) wrote :

My device also has orientation (that works) (HP Spectre x360 13").

I am attempting the bisection without the deb pkg now. Just keeping a log for if it's helpful.

1) 4.19.0+ Erorr displayed, touchpad didn't function
2) 4.19.0-rc8+ Did not show the error, touchpad functioned
3) 4.19.0+ No error, touchpad functioned
4) 4.19.0+ Erorr displayed, touchpad didn't function
5) 4.19.0+ Erorr displayed, touchpad didn't function
6) 4.19.0+ No error, touchpad functioned
7) 4.19.0+ Erorr displayed, touchpad didn't function
8) 4.19.0-rc6+ Erorr displayed, touchpad didn't function
9) 4.19.0-rc3+ Erorr displayed, touchpad functions
10) 4.19.0-rc3+ No error, touchpad functions
11) 4.18.0+ Error displayed, touchpad functions
12) 4.18.0+ Error displayed, touchpad functions
13) 4.18.0+ Error displayed, touchpad functions

My next post will contain the commit (need to switch back to that machine to post).

Out of curiousity, is there a reason bisection is not supported at the sub-version level? I.E v4.19.27-v4.20-rc1?

Thanks!

Fmstrat (fmstrat) wrote :

71f6fa90a353605bf25c36417c9ae529ac1a9a8d is the first bad commit
commit 71f6fa90a353605bf25c36417c9ae529ac1a9a8d
Author: Song, Hongyan <email address hidden>
Date: Fri Aug 3 14:45:59 2018 +0800

    HID: increase maximum global item tag report size to 256

    The maximum globale report size has changed from 32->...->96->128 in the past
    years. With the development usage of HID, the report_size max value 128 cannot
    satisfy all requirements.

    There are applications need to expose intrinsic metadata to camera stabilizing
    applications such as 3DFE application. 3DFE intrinsic is designed to express
    environmental information about sensor that may dynamically change while the
    sensor is running (such data include noise spectral density, bias standard
    deviation)

    A sensor data field is SENSOR_VALUE_PAIR that consists of a PROPERTYKEY and
    PROPVARIANT pair. It need to report a unique PROPERTYKEY for each data field.

    Take “Noise Spectral Density” as an example, it report count will be
    defined as below:

            "Size of Property key GUID(16 Byte) + property key index(4 Byte) +
            size of Noise Spectral Density value(4 Byte)"

    In this case, the data report max is totally 192(24Byte), which is larger than
    128, while max size 128 blocked it as illegal length. So increase the report
    size to satisfy it and more demands in the future.

    Signed-off-by: Song Hongyan <email address hidden>
    Signed-off-by: Jiri Kosina <email address hidden>

:040000 040000 c44ade4341c21e45c653cce63bee3a1411a9cc72 90c14f2502206b9b4884e49cbe1fdef5602a795d M drivers

Fmstrat (fmstrat) wrote :

Hrm, I went looking to see if I could help resolve, but I have to admit, at first glance I don't get it. The commit diff:

$ git diff 7a324b3f0535ceb0f6676fa20ca2a7b6213008cb 71f6fa90a353605bf25c36417c9ae529ac1a9a8d
diff --git a/drivers/hid/hid-core.c b/drivers/hid/hid-core.c
index 3da354af7a0a..ef009db512ee 100644
--- a/drivers/hid/hid-core.c
+++ b/drivers/hid/hid-core.c
@@ -406,7 +406,7 @@ static int hid_parser_global(struct hid_parser *parser, struct hid_item *item)

        case HID_GLOBAL_ITEM_TAG_REPORT_SIZE:
                parser->global.report_size = item_udata(item);
- if (parser->global.report_size > 128) {
+ if (parser->global.report_size > 256) {
                        hid_err(parser->device, "invalid report_size %d\n",
                                        parser->global.report_size);
                        return -1;

The increase from 128 to 256 should not create a scenario where the bug can exist. If it was originally below 128 and not throwing an error, then it should be below 256.

Fmstrat (fmstrat) wrote :

There are a lot of HID changes in the previous commit of 61c4fc1eaf736344904767d201b0d4f7a2ebaf79, so I guess it's possible there is perhaps something in the previous commit that is causing the 128/256 conflict.

Thanks again!

Kai-Heng Feng (kaihengfeng) wrote :

I think it didn't happen on older kernel because the report size 192 > 128 so the code bailed early.

Try this:
diff --git a/drivers/hid/hid-core.c b/drivers/hid/hid-core.c
index 9993b692598f..860e21ec6a49 100644
--- a/drivers/hid/hid-core.c
+++ b/drivers/hid/hid-core.c
@@ -1301,10 +1301,10 @@ static u32 __extract(u8 *report, unsigned offset, int n)
 u32 hid_field_extract(const struct hid_device *hid, u8 *report,
                        unsigned offset, unsigned n)
 {
- if (n > 32) {
- hid_warn(hid, "hid_field_extract() called with n (%d) > 32! (%s)\n",
+ if (n > 256) {
+ hid_warn(hid, "hid_field_extract() called with n (%d) > 256! (%s)\n",
                         n, current->comm);
- n = 32;
+ n = 256;
        }

        return __extract(report, offset, n);

Fmstrat (fmstrat) wrote :

I will give that a shot and report back. Should the implement function on line 1347 be changed as well?

Fmstrat (fmstrat) wrote :

That did the trick.

Mayur Virkar (mayurvirkar) wrote :

I have the same laptop. Neither my orientation is working, nor my mic.
PS: its a late 2018 model.

Kai-Heng Feng (kaihengfeng) wrote :
Changed in linux (Ubuntu):
assignee: nobody → Kai-Heng Feng (kaihengfeng)
Fmstrat (fmstrat) wrote :

As per Mayur's comments, orientation does work in 4.20, and in 5.0. Mic does not. I'm working on debugging and will submit a ticket for that if I can figure anything out.

description: updated
Changed in linux (Ubuntu Disco):
assignee: Kai-Heng Feng (kaihengfeng) → nobody
FatTony (fattony4) wrote :

Is there an easy way to disable the sensor until a kernel arrives that fixes the problem?

Launchpad Janitor (janitor) wrote :
Download full text (50.5 KiB)

This bug was fixed in the package linux - 5.0.0-11.12

---------------
linux (5.0.0-11.12) disco; urgency=medium

  * linux: 5.0.0-11.12 -proposed tracker (LP: #1824383)

  * hns3: PPU_PF_ABNORMAL_INT_ST over_8bd_no_fe found [error status=0x1]
    (LP: #1824194)
    - net: hns3: fix for not calculating tx bd num correctly

  * disco: unable to use iptables/enable ufw under -virtual kernel
    (LP: #1823862)
    - [Packaging] add bpfilter to linux-modules

  * Make shiftfs a module rather than built-in (LP: #1824354)
    - [Config] CONFIG_SHIFT_FS=m

  * shiftfs: chown sets untranslated ids in lower fs (LP: #1824350)
    - SAUCE: shiftfs: use translated ids when chaning lower fs attrs

  * [Hyper-V] KVP daemon fails to start on first boot of disco VM (LP: #1820063)
    - [Packaging] bind hv_kvp_daemon startup to hv_kvp device

linux (5.0.0-10.11) disco; urgency=medium

  * linux: 5.0.0-10.11 -proposed tracker (LP: #1823936)

  * Apparmor enforcement failure in lxc selftests (LP: #1823379)
    - SAUCE: apparmor: Restore Y/N in /sys for apparmor's "enabled"

  * systemd cause kernel trace "BUG: unable to handle kernel paging request at
    6db23a14" on Cosmic i386 (LP: #1813244)
    - openvswitch: fix flow actions reallocation

linux (5.0.0-9.10) disco; urgency=medium

  * linux: 5.0.0-9.10 -proposed tracker (LP: #1823228)

  * Packaging resync (LP: #1786013)
    - [Packaging] resync git-ubuntu-log
    - [Packaging] update helper scripts
    - [Packaging] resync retpoline extraction

  * Huawei Hi1822 NIC has poor performance (LP: #1820187)
    - net-next/hinic: replace disable_irq_nosync/enable_irq

  * Add uid shifting overlay filesystem (shiftfs) (LP: #1823186)
    - shiftfs: uid/gid shifting bind mount
    - shiftfs: rework and extend
    - shiftfs: support some btrfs ioctls
    - [Config] enable shiftfs

  * Cannot boot or install - have to use nomodeset (LP: #1821820)
    - Revert "drm/i915/fbdev: Actually configure untiled displays"

  * Disco update: v5.0.6 upstream stable release (LP: #1823060)
    - netfilter: nf_tables: fix set double-free in abort path
    - dccp: do not use ipv6 header for ipv4 flow
    - genetlink: Fix a memory leak on error path
    - gtp: change NET_UDP_TUNNEL dependency to select
    - ipv6: make ip6_create_rt_rcu return ip6_null_entry instead of NULL
    - mac8390: Fix mmio access size probe
    - mISDN: hfcpci: Test both vendor & device ID for Digium HFC4S
    - net: aquantia: fix rx checksum offload for UDP/TCP over IPv6
    - net: datagram: fix unbounded loop in __skb_try_recv_datagram()
    - net/packet: Set __GFP_NOWARN upon allocation in alloc_pg_vec
    - net: phy: meson-gxl: fix interrupt support
    - net: rose: fix a possible stack overflow
    - net: stmmac: fix memory corruption with large MTUs
    - net-sysfs: call dev_hold if kobject_init_and_add success
    - net: usb: aqc111: Extend HWID table by QNAP device
    - packets: Always register packet sk in the same order
    - rhashtable: Still do rehash when we get EEXIST
    - sctp: get sctphdr by offset in sctp_compute_cksum
    - sctp: use memdup_user instead of vmemdup_user
    - tcp: do not use ipv6 header for ipv4 flow
    - tipc: allow servic...

Changed in linux (Ubuntu Disco):
status: Confirmed → Fix Released
Ken Hughes (khughes-pacific) wrote :

This patch was reverted about a month ago, and made its way into the 5.1 kernel recently. The issue now showing up on my Dell Latitude 7400.

Alejandro Díaz-Caro (janusdc) wrote :

I got the same bug on the 5.2 kernel in my HP Spectre x360.

Affects me to. Also HP Spectre x360. Kernel 5.2.9-050209.

Alejandro Díaz-Caro (janusdc) wrote :

I confirm that the problem persists with kernel 5.2.9 on HP Spectre x360.

I am using kernel 5.1.9, which has no problem.

In addition, kernel 5.1.9 with linux-firmware-20190815.07b925b-1 has a problem with iwlwifi, so I had also to downgrade it to linux-firmware-20190618.acb56f2-1

Created attachment 284947
dmesg log

Hi

This affects all users having HP Spectre x360 model, with kernel version from 4.19 to 5.3 RC

Recently I have installed Fedora 30 on my HP Spectre x360 Laptop and found out that our logs are flooded with message:

hid-sensor-hub 001F:8087:0AC2.0003: hid_field_extract() called with n (192) > 32!

I also install for a test Fedora 31, as it is running newest kernel version, to see if this was fixed, but still I got the same output... Since I am not a developer but mere mortal, I need to ask, is it possible to fix this bug as it present since kernel version 4.19 and is making lot of issues to all of us that have Spectre laptop (not only Fedora but other distributions using kernel version higher the 4.19). As the result of that bug, system is generating insane amount of data into /var/log/message, and when I meant insane, its probably around tens of messages within a single second, so the logs grow to couple of GB within a day.

By doing a research I have found that another developer had the same issue as me, and he provided some sort of a bypass by patching hid-core.c in the drivers/hid folder and hid.h in the library/linux

Please refer to the link below:

https://patchwork.kernel.org/patch/11052949

and

https://patchwork.kernel.org/patch/11052951

If it is not a problem, can you please patch this bug and put it into a newer kernel version 5.3 kernel which will be released soon? At this point, our PC is quite unusable, as the logs are being filled up quickly, and not being able to have larger disk space we are forced to write a script to delete logs every day...

FatTony (fattony4) wrote :

Problem persists on kernel 5.3.1-300.fc31.x86_64 (Fedora 31).

Nikita Koval (nikodll) wrote :

Also affects Dell XPS / Ubuntu Eoan 5.3.0-18-generic #19-Ubuntu

Lukas Raab (lukas-raab) wrote :

Also affects Lenovo Thinkpad X1 Yoga 4th on 5.3.5-arch1-1-ARCH

Inco Gnito (incognito666) wrote :

HP Spectre x360 on 19.10 with 5.3.0-19-generic has this issue as well.
The sensor "id": hid-sensor-hub 001F:8087:0AC2.0004

Tip: Add the line `:msg, contains, "hid-sensor-hub 001F:8087:0AC2.0004" ~` at the top of you /etc/rsyslog.d/50-default.conf to temporarily get rid of this message in your logs

mm_202 (mastermind202) wrote :

HP Spectre x360 affected with kernel 5.3.0-19-generic.

Is there a way to turn this sensor off??

Mark Borgerding (3y9-mlrs-fkz) wrote :

This is blasting 3.45 million messages into my dmesg per day ( at least no longer in syslog thanks to @incognito666 )

Dell XPS 13 7390 2-in-1 Ubuntu 19.10 kernel 5.3.0-19-generic

mm_202 (mastermind202) on 2019-10-27
summary: - hid-sensor-hub spamming dmesg in 4.20
+ hid-sensor-hub spamming dmesg in 4.20 - 5.3
mm_202 (mastermind202) wrote :

This bug report has a status of "Fix Released" and looks like it can't be changed (at least not by me), should we open a new bug report?

It seems that this is also related to the mic not working, as mayurvirkar mentioned, so I'd love to get as much attention on this as possible.

Connor Kuehl (connork) wrote :

These patches were applied today[1] and therefore the fix is not released yet. Sorry for the confusion, everyone. Setting this to "Fix committed".

Changed in linux (Ubuntu Disco):
status: Fix Released → Fix Committed
Connor Kuehl (connork) wrote :

and I meant to cite this as [1] in comment #39: https://lists.ubuntu.com/archives/kernel-team/2019-November/105342.html

Connor Kuehl (connork) wrote :

Okay, looks like an additional patch set has just landed that rate limits this error when the threshold is spilled over and that's being tracked here and THAT is what is fix committed: https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1850600

The patch for this bug raised the threshold and that is in fact fix released.

Changed in linux (Ubuntu Disco):
status: Fix Committed → Fix Released
mm_202 (mastermind202) wrote :

@connork: Thank you for the update!

I'm unfamiliar with the patch to kernel release process.
How long do you think before it shows up for the 5.3.x kernel?
Is there a place to watch/monitor it's progress?
Or is https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1850600 the best place?

Yesterday (2019-11-25) I installed the recommended BIOS updates from HP on a HP x360 Zbook.

Now I am getting this exact same problem with KUbuntu 19.10 running "Linux ao-x360 5.3.0-23-generic #25-Ubuntu SMP Tue Nov 12 09:22:33 UTC 2019 x86_64 x86_64 x86_64 GNU/Linux"

I just did a quick "ls -l" comparison over time and the system is writing about 308kB/min (5kB/sec) to syslog and kern.log. Or, in an hour, the two files increase in size about 20 MB each.

The message is

kernel: [ 1627.620171] hid-sensor-hub 001F:8087:0AC2.0003: hid_field_extract() called with n (192) > 32! (kworker/3:2)

I'm concerned that this is going to rapidly degrade the hard drives in the system.

Also happening with HP Zbook x360, but only recently started (today).

As a workaround to stop your HD from filling up with this, create the file

/etc/rsyslog.d/10-hidsensor.conf

With the two lines:

# Disable runaway messages:
:msg, contains, "hid-sensor-hub 001F:8087:0AC2.0003" ~

Then run

sudo service rsyslog restart

(In reply to dovla091 from comment #0)

>
> At this point,
> our PC is quite unusable, as the logs are being filled up quickly, and not
> being able to have larger disk space we are forced to write a script to
> delete logs every day...

dovla091,

You can stop these messages by modifying your system to not log these messages. For example, if you have rsyslog and the directory /etc/rsyslog.d/

Then you can create the file:

/etc/rsyslog.d/10-hidsensor.conf

with content:

#Disable runaway messages:
:msg, contains, "hid-sensor-hub 001F:8087:0AC2.0003: hid_field_extract() called with n (192) > 32!" stop

And once that file exists, when you restart rsyslog (e.g. sudo system rsyslog restart) the messages will no longer hit your logs.

Changed in linux:
importance: Unknown → High
status: Unknown → Confirmed
To post a comment you must log in.
This report contains Public information  Edit
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.