Bug 1432481 - Lenovo T460p trackpoint/touchpad rarely not working (first seen after kernel-4.11.0-0.rc{1.git0.1 -> 2.git0.2}.fc27.x86_64 update)
Summary: Lenovo T460p trackpoint/touchpad rarely not working (first seen after kernel-...
Keywords:
Status: NEW
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: rawhide
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Kernel Maintainer List
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2017-03-15 13:35 UTC by Jan Pokorný [poki]
Modified: 2019-12-15 23:45 UTC (History)
16 users (show)

Fixed In Version:
Clone Of:
: 1466888 (view as bug list)
Environment:
Last Closed: 2017-03-29 17:32:25 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
dmesg output (3.84 KB, text/plain)
2018-03-08 12:21 UTC, Vladyslav Shtabovenko
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Red Hat Bugzilla 1466888 0 unspecified CLOSED Lenovo T460p trackpoint/touchpad: possible circular locking dependency detected (psmouse_mutex) 2021-02-22 00:41:40 UTC

Internal Links: 1466888

Description Jan Pokorný [poki] 2017-03-15 13:35:33 UTC
Symptoms beside cursor not working:


> kernel: psmouse serio2: Failed to deactivate mouse on synaptics-pt/serio0
> [..., but within the same second]
> kernel: psmouse serio2: Failed to enable mouse on synaptics-pt/serio0
> [..., but within the next second]
> kernel: psmouse serio2: trackpoint: IBM TrackPoint firmware: 0x0e, buttons: 3/3

Only tried this once (before rebooting with a former kernel).

Comment 1 Jan Pokorný [poki] 2017-03-16 11:50:51 UTC
After couple of more tries to reproduce this issue, I conclude this issue
is quite rare, couldn't reproduce that anymore.

Note that the original observation was made freshly after update, but
I doubt there is any after-update-after-reboot triggering mechanism
that could induce this in that very moment.

I'll close this bug in week's time if no more occurrence is observed.

Comment 2 Jan Pokorný [poki] 2017-03-16 17:03:19 UTC
Actually hit it, accidentally, again (same kernel as reported) when the
battery in laptop got drained after I attached the power adapter and
booted again.

I indeed can observe that in that case, filesystem consistency check
was triggered ("systemd-fsck[806]: boot: recovering journal"), and I wonder
if this was perhaps what influenced the startup timing (if this bug can be
attributed just to some kind of race condition -- something hard to tell).

To provide more context, I am booting into text console and have gpm
installed and enabled, and can affirm that the cursor was not working
even in this VT mode (as opposed to what I can observe normally).
I checked that gpm did not complain in any way.

Also I've found out the messages stated in [comment 0] are present in
the journal/log regardless if this bug is reproduced.

Comment 3 Jan Pokorný [poki] 2017-03-29 17:31:50 UTC
It's not reasonable to keep this bug lingering around forever
as I haven't hit this issue recently anymore (with never releases),
including the boot-after-no-power-shutdown scenario.

Note that I haven't been updating systemd or udev around the time
this issue popped up.

Will keep an eye on this issue if it recidivates and will reopen
this bug it there's a need.

Comment 4 Jan Pokorný [poki] 2017-03-30 12:26:29 UTC
re [comment 3]: s/never/newer/, apparently

Comment 5 Jan Pokorný [poki] 2017-04-03 14:05:20 UTC
Just for posterity (if it is found relevant in the future), I'll share
a newer finding with 4.11.0-0.rc4.git3.1.fc27.x86_64:

======================================================
[ INFO: possible circular locking dependency detected ]
4.11.0-0.rc4.git3.1.fc27.x86_64 #1 Not tainted
-------------------------------------------------------
kworker/5:1/78 is trying to acquire lock:
 (s_active#92){++++.+}, at: [<ffffffffaf36bfd5>] kernfs_remove_by_name_ns+0x45/0xa0

but task is already holding lock:
 (psmouse_mutex){+.+.+.}, at: [<ffffffffaf75059c>] psmouse_disconnect+0x6c/0x150

which lock already depends on the new lock.

the existing dependency chain (in reverse order) is:
[TTM] Zone  kernel: Available graphics memory: 16168954 kiB
[TTM] Zone   dma32: Available graphics memory: 2097152 kiB
[TTM] Initializing pool allocator
[TTM] Initializing DMA pool allocator
nouveau 0000:02:00.0: DRM: VRAM: 2048 MiB
nouveau 0000:02:00.0: DRM: GART: 1048576 MiB
nouveau 0000:02:00.0: DRM: Pointer to TMDS table invalid
nouveau 0000:02:00.0: DRM: DCB version 4.0
nouveau 0000:02:00.0: DRM: Pointer to flat panel table invalid

-> #1 (psmouse_mutex){+.+.+.}:
       lock_acquire+0xb7/0x210
       __mutex_lock+0x83/0x9e0
       mutex_lock_interruptible_nested+0x1b/0x20
       psmouse_attr_set_helper+0x30/0x120
       dev_attr_store+0x18/0x30
       sysfs_kf_write+0x42/0x60
       kernfs_fop_write+0x151/0x1e0
       __vfs_write+0x37/0x160
       vfs_write+0xc3/0x1e0
       SyS_write+0x58/0xc0
       do_syscall_64+0x6c/0x1f0
       return_from_SYSCALL_64+0x0/0x7a

-> #0 (s_active#92){++++.+}:
       __lock_acquire+0x13a5/0x13b0
       lock_acquire+0xb7/0x210
       __kernfs_remove+0x271/0x370
       kernfs_remove_by_name_ns+0x45/0xa0
       remove_files.isra.1+0x35/0x70
       sysfs_remove_group+0x44/0xa0
       trackpoint_disconnect+0x24/0x40
       psmouse_disconnect+0xf7/0x150
       serio_disconnect_driver+0x32/0x40
       serio_driver_remove+0x15/0x20
       device_release_driver_internal+0x160/0x210
       device_release_driver+0x12/0x20
       serio_disconnect_port+0x98/0xb0
       serio_reconnect_subtree+0x51/0xb0
       serio_handle_event+0x17f/0x290
       process_one_work+0x260/0x750
       worker_thread+0x4e/0x4a0
       kthread+0x12c/0x150
       ret_from_fork+0x31/0x40

other info that might help us debug this:
 Possible unsafe locking scenario:
       CPU0                    CPU1
       ----                    ----
  lock(psmouse_mutex);
                               lock(s_active#92);
                               lock(psmouse_mutex);
  lock(s_active#92);

 *** DEADLOCK ***
6 locks held by kworker/5:1/78:
 #0:  ("events_long"){.+.+.+}, at: [<ffffffffaf0d3d7b>] process_one_work+0x1db/0x750
 #1:  (serio_event_work){+.+.+.}, at: [<ffffffffaf0d3d7b>] process_one_work+0x1db/0x750
 #2:  (serio_mutex){+.+.+.}, at: [<ffffffffaf73fd7b>] serio_handle_event+0x2b/0x290
 #3:  (&dev->mutex){......}, at: [<ffffffffaf63c849>] device_release_driver_internal+0x39/0x210
 #4:  (&serio->drv_mutex){+.+.+.}, at: [<ffffffffaf73edf0>] serio_disconnect_driver+0x20/0x40
 #5:  (psmouse_mutex){+.+.+.}, at: [<ffffffffaf75059c>] psmouse_disconnect+0x6c/0x150

stack backtrace:
CPU: 5 PID: 78 Comm: kworker/5:1 Not tainted 4.11.0-0.rc4.git3.1.fc27.x86_64 #1
Hardware name: LENOVO 20FXS0BB14/20FXS0BB14, BIOS R07ET63W (2.03 ) 03/15/2016
Workqueue: events_long serio_handle_event
Call Trace:
 dump_stack+0x8e/0xd1
 print_circular_bug+0x1b6/0x210
 __lock_acquire+0x13a5/0x13b0
 lock_acquire+0xb7/0x210
 ? kernfs_remove_by_name_ns+0x45/0xa0
 __kernfs_remove+0x271/0x370
 ? kernfs_remove_by_name_ns+0x45/0xa0
 ? kernfs_find_ns+0x7e/0x140
 kernfs_remove_by_name_ns+0x45/0xa0
 remove_files.isra.1+0x35/0x70
 sysfs_remove_group+0x44/0xa0
 trackpoint_disconnect+0x24/0x40
 psmouse_disconnect+0xf7/0x150
 serio_disconnect_driver+0x32/0x40
 serio_driver_remove+0x15/0x20
 device_release_driver_internal+0x160/0x210
 device_release_driver+0x12/0x20
 serio_disconnect_port+0x98/0xb0
 serio_reconnect_subtree+0x51/0xb0
 serio_handle_event+0x17f/0x290
 process_one_work+0x260/0x750
 ? process_one_work+0x1db/0x750
 worker_thread+0x4e/0x4a0
 ? process_one_work+0x750/0x750
 kthread+0x12c/0x150
 ? kthread_create_on_node+0x60/0x60
 ret_from_fork+0x31/0x40

Comment 6 Jan Pokorný [poki] 2017-06-01 18:55:42 UTC
Happened to me again, and again it was related to battery draining
(see the top of [comment 2]), but this time it was:

1. laptop died because of battery was drained
2. started charging, booted up
3. updated, incl. this kernel update:
   kernel-4.12.0-0.rc3.git0.2.fc27.x86_64
   (while running 4.12.0-0.rc2.git3.1.fc27.x86_64 in 1. and 3.,
    the new one was used for 5.)
4. rebooted
5. issue reproduced

# journalctl -b-1 | grep -e psmouse -e gpm
> Jun 01 20:31:47 betenoire kernel: psmouse serio1: synaptics: queried max coordinates: x [..5676], y [..4758]
> Jun 01 20:31:47 betenoire kernel: psmouse serio1: synaptics: queried min coordinates: x [1266..], y [1096..]
> Jun 01 20:31:47 betenoire kernel: psmouse serio1: synaptics: Touchpad model: 1, fw: 8.2, id: 0x1e2b1, caps: 0xf006a3/0x943300/0x12e800/0x10000, board id: 3053, fw id: 2010421
> Jun 01 20:31:47 betenoire kernel: psmouse serio1: synaptics: serio: Synaptics pass-through port at isa0060/serio1/input0
> Jun 01 20:31:48 betenoire kernel: psmouse serio2: trackpoint: IBM TrackPoint firmware: 0x0e, buttons: 3/3
> Jun 01 20:35:25 betenoire kernel: psmouse serio2: Failed to deactivate mouse on synaptics-pt/serio0
> Jun 01 20:35:25 betenoire /usr/sbin/gpm[3277]: *** info [daemon/startup.c(136)]:
> Jun 01 20:35:25 betenoire /usr/sbin/gpm[3277]: Started gpm successfully. Entered daemon mode.
> Jun 01 20:35:25 betenoire audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 subj=system_u:system_r:init_t:s0 msg='unit=gpm comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
> Jun 01 20:35:26 betenoire kernel: psmouse serio2: Failed to enable mouse on synaptics-pt/serio0
> Jun 01 20:35:27 betenoire kernel: psmouse serio2: trackpoint: IBM TrackPoint firmware: 0x0e, buttons: 3/3

(note that I am using gpm service for all the time this bug exposes
itself, so added that to the points of interest above)

There was no such issue as in [comment 5] in the logs for that boot.

That being said, reopening this bug.

Comment 7 Jan Pokorný [poki] 2017-06-30 16:21:19 UTC
Re [comment 5]: there's no direct causality evidence (actually the
two erroneous observations have been mutually exclusive so far),
hence separated the locking issue as [bug 1466888].

Comment 8 Vladyslav Shtabovenko 2017-08-28 02:22:36 UTC
I'm also affected by this bug on my T460p. I'm using Fedora 26 with the latest
official kernel 4.12.8-300.fc26.x86_64. The bug, however, was present also on earlier kernels. This is how it looks like after boot when the touchpoint is not working

[   59.060428] rfkill: input handler disabled
[  219.883111] psmouse serio2: trackpoint: IBM TrackPoint firmware: 0x0e, buttons: 3/3
[  220.113143] input: TPPS/2 IBM TrackPoint as /devices/platform/i8042/serio1/serio2/input/input25
[  220.731996] psmouse serio2: Failed to deactivate mouse on synaptics-pt/serio0
[  221.211902] psmouse serio2: Failed to enable mouse on synaptics-pt/serio0

The workaround is either to wait 2-3 minutes or to suspend the machine and then resume from the suspend after a few seconds. After that the trackpoint starts working again. 

Would be really nice if someone from the devs could have a look at it. Apart from that annoyance my T460p is really a perfect Linux machine.

Comment 9 Jan Pokorný [poki] 2017-11-09 19:26:07 UTC
Just a brief update, haven't observed this problem for several months
already.  I am keeping with the newest kernels in Rawhide, plus I haven't
run into battery draining situation for approximately just as long if
it can have any relevance.

Comment 10 Vladyslav Shtabovenko 2017-11-11 06:00:19 UTC
Well, my T460p is still affected. I rarely reboot the machine, mostly just suspend and resume. After resume from suspend the probability that the trackpoint is blocked for 2 minutes is around 20-30%. Kernel version 4.13.11-200.fc26.x86_64, lipinput 1.9.0.1.fc26

Comment 11 Ryan O'Hara 2017-11-28 18:04:49 UTC
This is affecting me as well. I've tried using the "psmouse.synaptics_intertouch=1" kernel parameter it makes no different. I've even trying patching the kernel to include the firwmware_id (LEN2018) in the smbus_pnp_ids array hoping that it would help as it did with the seemingly related patch for the X1 Carbon 5 laptop. No improvement.

As far as I can tell, the system is not using RMI/SMbus as expected with the "psmouse.synaptics_intertouch=1" option. My theory is/was that using RMI/SMbus would resolve the problem.

Could really use some guidance here since the laptop is unusable unless I have a external mouse, which isn't always possible.

Comment 12 Jan Lieskovsky 2017-12-21 17:28:33 UTC
Same issue here on Fedora 27 with 4.14.6-300.fc27.x86_64. I my case not whole touchpad wasn't working, just it left and right buttons weren't working for couple of minutes ("clicking the touchpad" could be used as a "replacement" for left click during that time).

When the buttons weren't working:
# libinput debug-events

didn't show any events for left / right button clicks (but has shown events when clicking the touchpad itself).

After 2-3 minutes the issue "disappeared somehow".

JFTR: This is Fedora 27 with MATE Desktop installed (should it matter somehow).

Comment 13 Jan Pokorný [poki] 2018-02-01 13:24:12 UTC
Happened to me again, this time the trackpoint never started working
upon boot, the touchpad was OK at least at the point I tried, which
was couple of minutes after boot.  This aspect may or may not be
different to my previous observations, I don't remember TBH.

Kernel used: 4.15.0-1.fc28.x86_64

From the journal:

# journalctl -b-1 --no-hostname | grep -Ei 'psmouse|trackpoint|synaptics|smbus'
> Feb 01 10:56:42 kernel: psmouse serio1: synaptics: queried max coordinates: x [..5676], y [..4758]
> Feb 01 10:56:43 kernel: psmouse serio1: synaptics: queried min coordinates: x [1266..], y [1096..]
> Feb 01 10:56:43 kernel: psmouse serio1: synaptics: Trying to set up SMBus access
> Feb 01 10:56:43 kernel: psmouse serio1: synaptics: SMbus companion is not ready yet
> Feb 01 10:56:43 kernel: psmouse serio1: synaptics: Touchpad model: 1, fw: 8.2, id: 0x1e2b1, caps: 0xf006a3/0x943300/0x12e800/0x10000, board id: 3053, fw id: 2010421
> Feb 01 10:56:43 kernel: psmouse serio1: synaptics: serio: Synaptics pass-through port at isa0060/serio1/input0
> Feb 01 10:56:43 kernel: input: SynPS/2 Synaptics TouchPad as /devices/platform/i8042/serio1/input/input5
> Feb 01 10:56:43 kernel: psmouse serio2: trackpoint: IBM TrackPoint firmware: 0x0e, buttons: 3/3
> Feb 01 10:56:43 kernel: input: TPPS/2 IBM TrackPoint as /devices/platform/i8042/serio1/serio2/input/input8
> Feb 01 10:57:08 kernel: i801_smbus 0000:00:1f.4: SPD Write Disable is set
> Feb 01 10:57:08 kernel: i801_smbus 0000:00:1f.4: SMBus using PCI interrupt
> Feb 01 10:57:09 kernel: psmouse serio1: synaptics: queried max coordinates: x [..5676], y [..4758]
> Feb 01 10:57:09 kernel: psmouse serio1: synaptics: queried min coordinates: x [1266..], y [1096..]
> Feb 01 10:57:09 kernel: psmouse serio1: synaptics: Trying to set up SMBus access
> Feb 01 10:57:09 kernel: rmi4_smbus 7-002c: registering SMbus-connected sensor
> Feb 01 10:57:09 kernel: rmi4_f01 rmi4-00.fn01: found RMI device, manufacturer: Synaptics, product: TM3053-006, fw id: 2010421
> Feb 01 10:57:09 kernel: input: Synaptics TM3053-006 as /devices/rmi4-00/input/input22


The only difference compared to the boot where trackpoint works correctly is these lines
following after

>  input: Synaptics TM3053-006 as /devices/rmi4-00/input/input22

suggesting that the trackpoint was reprobed and assigned new serioX:

> kernel: psmouse serio3: trackpoint: IBM TrackPoint firmware: 0x0e, buttons: 3/3
> kernel: input: TPPS/2 IBM TrackPoint as /devices/rmi4-00/rmi4-00.fn03/serio3/input/input23

within one second after the previous given line.

Comment 14 Jan Pokorný [poki] 2018-02-07 14:36:48 UTC
Hit something similar today again; perhaps 4.15.0-1.fc28.x86_64 made
some kind of race condition more probable, wild guess estimate of
reproducing is currently 1 hit in 20 boots.

This time, the messages were accompanied with "Failed to deactivate"
and "Failed to enable mouse" messages again (see [comment 0]).

I guess I'll try resorting to psmouse.proto=bare on kernel command-line,
though I am not sure if that's the correct equivalent of module-based
approach (for some reason, psmouse is not compiled as a kernel module):

https://wiki.archlinux.org/index.php/TrackPoint#Trackpoint_is_not_detected_or_is_detected_after_X_minutes
https://bugzilla.kernel.org/show_bug.cgi?id=33292

Comment 15 Jan Pokorný [poki] 2018-02-09 09:45:35 UTC
To answer to myself from [comment 14], psmouse.proto=bare on kernel
command line indeed works, but despite it may make trackpoint detected
reliably, it doesn't work well -- there's a noticable lag with the
cursor, and it doesn't interact well with some features of libinput
that are vital for me at the moment.

With psmouse.proto=imps ditto.

Perhaps what's missing to satisfy me is the patch from the linked bug:
https://bugzilla.kernel.org/show_bug.cgi?id=33292#c27

Comment 16 Vladyslav Shtabovenko 2018-03-08 12:19:50 UTC
While reading the comments to 

https://bugzilla.redhat.com/show_bug.cgi?id=1442699

I found an interesting piece of information. Apparently one can reproduce 
our bug using the following command

echo -n "reconnect" | sudo tee   /sys/bus/serio/devices/serio1/drvctl

If you execute this often enough (10 times or so, sometimes less), the trackpoint
will freeze with the same symptoms as after suspend. After 2-3 minutes it will
then start working again.

I hope that this should be sufficient for a kernel developer to reproduce the issue without doing numerous suspend-resume cycles. The problem is clearly
related to this reconnect event that would randomly fail and freeze the trackpoint for several minutes.

Comment 17 Vladyslav Shtabovenko 2018-03-08 12:21:07 UTC
Created attachment 1405827 [details]
dmesg output

This is how it looks in dmesg when running the above mentioned command multiple times sequentially

Comment 18 Pavel Raiskup 2018-04-04 20:58:55 UTC
With 'BOOT_IMAGE=/vmlinuz-4.15.13-300.fc27.x86_64' it's not reproducible
anymore.

Comment 19 Jan Pokorný [poki] 2018-04-10 12:23:30 UTC
re [comment 14]:

Mentioned a possibility to have psmouse compiled as a module
and hence to possibly avoid reboots so as to get trackpoint
functional in the recent devel ML discussion on such topic:

https://lists.fedoraproject.org/archives/list/devel@lists.fedoraproject.org/message/PZ4QYE22LVRMEY4NPE2FSESXNTA2B7UC/

Comment 20 Florian Alber 2018-10-30 13:45:55 UTC
Hi,

I get this bug from time to time and it isn't depended on the current kernel version. I'm working on a Thinkpad Yoga 260 with Fedora 28 and 4.18.16.
Randomly my trackpoint freezes around 1-3 time per week and I can fix it by restarting the whole machine or by entering this command:

sudo sh -c 'echo -n "elantech" > /sys/bus/serio/devices/serio1/protocol'

afterwards everything is back to normal. Hope I can help with this info.

Greetings,
albflo


Note You need to log in before you can comment on or make changes to this bug.