search

VoodooSMBus / VoodooRMI

Synaptic Trackpad driver over SMBus/I2C for macOS
GNU General Public License v2.0
235 stars 18 forks source link

Thinkpad x1 carbon gen 6 trackpad stops working after sleep on macOS 13.1 #154

Open tvannoy opened 1 year ago

tvannoy commented 1 year ago

Describe the bug

Trackpad fails to suspend, then doesn't work upon wake.

This bug appears to have surfaced after I upgraded to macOS 13.1. I'm using a 6th gen Thinkpad X1 Carbon. As far as I remember, the trackpad never stopped working after wake on macOS 12.x. This bug occurs every time I sleep the laptop on macOS 13.1.

The error occurs in rmi_f01_suspend(), line 389: https://github.com/VoodooSMBus/VoodooRMI/blob/998761a22c8ada7c90e8b72f3998c2fc3ba439a5/VoodooRMI/Functions/F01.cpp#L389

I tried tracing through the call stack beyond rmi_f01_suspend(), but ultimately didn't get very far becuase I'm not familiar with macOS kext development. The reported error code is -110; as best as I could tell, this error message most likely propagated up from some VoodooSMBus function.

This is the call stack I think is happening: rmi_f01_suspend --> RMISMBus::blockWrite() --> VoodooSMBusDeviceNum::writeBlockData() --> VoodooSMBusControllerDriver::writeBlockData() --> VoodooSMBusControllerDriver::transfer() --> command_gate->run_action(). I suspect the error is propagating from the IOCommandGate calls, but I'm not sure.

System Details

I've also tried with a VoodooSMBus kext built using the latest commit in the dev branch: (9226dc). I've had the same results with the official debug releases and custom-built kexts, which include additional commits not in the released versions.

Initially, I was thinking this bug might be related to https://github.com/VoodooSMBus/VoodooSMBus/pull/41, but the VoodooSMBus kext I built included that PR.

Kexts enabled/disabled

Enabled

Disabled

I've also deleted VoodooPS2Mouse, as recommended in the VoodooSMBus README.

To Reproduce

Steps to reproduce the behavior:

  1. Put the laptop to sleep, either by closing the lid or using the Apple menu
  2. Wake the laptop from sleep

Expected behavior

Trackpad gets suspended upon sleep, and works on wake.

Log

Log was gathered using sudo dmesg | grep -i vrmi and DebugEnhancer.kext.

Relevant section of the log after sleep:

[  119.211702]: VRMI - Debug: Sleep
[  119.414268]: VRMI - Error: Failed to write sleep mode: -110.
[  119.616897]: VRMI - Error: rmi_driver_clear_irq_bits: Filaed to change enabled interrupts!
[  142.791488]: VRMI - Error: Failed to reset trackpad!
[  215.469095]: VRMI - Debug: Sleep
[  215.671858]: VRMI - Error: Failed to write sleep mode: -110.
[  215.873936]: VRMI - Error: smb_get_command_code: Failed to write mapping table data
[  215.873943]: VRMI - Error: rmi_driver_clear_irq_bits: Filaed to change enabled interrupts!
[  264.729684]: VRMI - Error: Failed to reset trackpad!

Longer log excerpt: The rest of the log is just debug messages showing trackpad inputs

[    7.755830]: VRMI - Info: SMBus version 2
[    7.755979]: VRMI - Debug: Config TrackpointMultiplier loaded: a -> a
[    7.755984]: VRMI - Debug: Config TrackpointScrollMultiplierX loaded: a -> 1e
[    7.755986]: VRMI - Debug: Config TrackpointScrollMultiplierY loaded: a -> 1e
[    7.755988]: VRMI - Debug: Config TrackpointDeadzone loaded: 1 -> 1
[    7.755990]: VRMI - Debug: Config DisableWhileTypingTimeout loaded: 7d0 -> fa
[    7.755993]: VRMI - Debug: Config DisableWhileTrackpointTimeout loaded: 7d0 -> fa
[    7.755995]: VRMI - Debug: Config ForceTouchMinPressure loaded: 50 -> 5a
[    7.755997]: VRMI - Debug: Config ForceTouchEmulation loaded: 1 -> 1
[    7.756023]: VRMI - Debug: Config MinYDiffThumbDetection loaded: c8 -> c8
[    7.756026]: VRMI - Debug: Config FingerMajorMinorDiffMax loaded: a -> a
[    7.756027]: VRMI - Debug: Config PalmRejectionWidth loaded: f -> a
[    7.756029]: VRMI - Debug: Config PalmRejectionHeight loaded: 50 -> 3c
[    7.756031]: VRMI - Debug: Config PalmRejectionTrackpointHeight loaded: 14 -> 14
[    7.756032]: VRMI - Debug: Updating Configuration
[    7.756038]: VRMI - Info: RMI Bus (DEBUG) Starting up!
[    7.762159]: VRMI - Debug: rmi_probe_interrupts: Counting IRQs
[    7.783638]: VRMI - Debug: IRQ Count: 7
[    7.783656]: VRMI - Debug: rmi_init_functions: Creating functions
[    7.785702]: VRMI - Info: Initializing F34.
[    7.785706]: VRMI - Debug: Function F34 - IRQs: 1 CMD Base: 0 CTRL Base: 78 DATA Base: 0 QRY Base: 129 VER: 0
[    7.785709]: VRMI - Info: F34 not implemented
[    7.787729]: VRMI - Info: Initializing F01.
[    7.787733]: VRMI - Debug: Function F1 - IRQs: 1 CMD Base: 127 CTRL Base: 82 DATA Base: 19 QRY Base: 138 VER: 0
[    7.805533]: VRMI - Info: Found RMI4 device, manufacturer: Synaptics, product: TM3289-021, fw id: 2698617
[    7.813647]: VRMI - Info: Initializing F03.
[    7.813651]: VRMI - Debug: Function F3 - IRQs: 1 CMD Base: 0 CTRL Base: 0 DATA Base: 22 QRY Base: 167 VER: 0
[    7.818734]: VRMI - Info: Initializing F11.
[    7.818737]: VRMI - Debug: Function F11 - IRQs: 2 CMD Base: 128 CTRL Base: 88 DATA Base: 38 QRY Base: 169 VER: 1
[    7.847135]: VRMI - Info: Initializing F30.
[    7.847138]: VRMI - Debug: Function F30 - IRQs: 1 CMD Base: 256 CTRL Base: 270 DATA Base: 256 QRY Base: 352 VER: 0
[    7.851620]: VRMI - Debug: F30: Found Button 1
[    7.853637]: VRMI - Info: Initializing F54.
[    7.853641]: VRMI - Debug: Function F54 - IRQs: 1 CMD Base: 351 CTRL Base: 284 DATA Base: 258 QRY Base: 354 VER: 0
[    7.853644]: VRMI - Info: F54 not implemented
[    7.869588]: VRMI - Debug: F03 - Consumed <ptr>h (14) from PS2 guest
[    7.970639]: VRMI - Debug: F03 - PS2 Command [Send: 0 Receive: 2 cmd: ff]
[    7.985829]: VRMI - Debug: F03 - Recieved data over PS2: fa
[    8.044601]: VRMI - Debug: F03 - Recieved data over PS2: aa
[    8.044604]: VRMI - Debug: F03 - Recieved data over PS2: 0
[    8.044610]: VRMI - Debug: F03 - PS2 Command [Send: 0 Receive: 2 cmd: e1]
[    8.059483]: VRMI - Debug: F03 - Recieved data over PS2: fa
[    8.059487]: VRMI - Debug: F03 - Recieved data over PS2: 3
[    8.059488]: VRMI - Debug: F03 - Recieved data over PS2: 6
[    8.560540]: VRMI - Debug: F03 - PS2 Command [Send: 1 Receive: 2 cmd: e2]
[    8.576101]: VRMI - Debug: F03 - Recieved data over PS2: fa
[    8.583605]: VRMI - Debug: F03 - Recieved data over PS2: fa
[    8.652655]: VRMI - Debug: F03 - Recieved data over PS2: aa
[    8.652679]: VRMI - Debug: F03 - Recieved data over PS2: 0
[    8.652685]: VRMI - Debug: F03 - PS2 Command [Send: 1 Receive: 0 cmd: e8]
[    8.660158]: VRMI - Debug: F03 - Recieved data over PS2: fa
[    8.667573]: VRMI - Debug: F03 - Recieved data over PS2: fa
[    8.769942]: VRMI - Debug: Wakeup
[    9.168619]: VRMI - Debug: F03 - PS2 Command [Send: 0 Receive: 0 cmd: e7]
[    9.186435]: VRMI - Debug: F03 - Recieved data over PS2: fa
[    9.687382]: VRMI - Debug: F03 - PS2 Command [Send: 1 Receive: 0 cmd: f3]
[    9.720138]: VRMI - Debug: F03 - Recieved data over PS2: fa
[    9.778848]: VRMI - Debug: F03 - Recieved data over PS2: fa
[   10.552244]: hook_thread_userret calleduserret(597): invoking callback; 0/4 remainingVRMI - Debug: F03 - PS2 Command [Send: 0 Receive: 0 cmd: f4]
[   10.576195]: VRMI - Debug: F03 - Recieved data over PS2: fa
[   11.076268]: VRMI - Info: Finish PS2 init
[   42.423757]: VRMI - Debug: F11 Packet
[   42.436750]: VRMI - Debug: F11 Packet
[   42.436762]: VRMI - Debug: Velocity: 0 0 Zone: 0
[   42.436766]: VRMI - Debug: Finger num: 0 (valid) (913, 653) [Z: 45 WX: 1 WY: 0 FingerType: 0 Pressure : 0 Button: 0]
[   42.441852]: VRMI - Debug: F11 Packet
[   42.441863]: VRMI - Debug: Finger num: 0 (valid) (913, 653) [Z: 45 WX: 1 WY: 0 FingerType: 2 Pressure : 0 Button: 0]
[   42.447091]: Sandbox apply: neagent[568] <bytes>VRMI - Debug: F11 Packet
[   42.451664]: VRMI - Debug: Finger num: 0 (valid) (946, 660) [Z: 49 WX: 0 WY: 0 FingerType: 2 Pressure : 0 Button: 0]
[   42.456693]: VRMI - Debug: F11 Packet
[   42.456705]: VRMI - Debug: Finger num: 0 (valid) (946, 660) [Z: 49 WX: 0 WY: 0 FingerType: 2 Pressure : 0 Button: 0]
[   42.465340]: Sandbox apply: WiFiVelocityAgent[569] <bytes>VRMI - Debug: F11 Packet
[   42.466459]: VRMI - Debug: Finger num: 0 (valid) (1007, 671) [Z: 55 WX: 0 WY: 0 FingerType: 2 Pressure : 0 Button: 0]
[   42.471547]: VRMI - Debug: F11 Packet
[   42.471559]: VRMI - Debug: Finger num: 0 (valid) (1007, 671) [Z: 55 WX: 0 WY: 0 FingerType: 2 Pressure : 0 Button: 0]
[   42.481234]: VRMI - Debug: F11 Packet
[   42.481248]: VRMI - Debug: Finger num: 0 (valid) (1074, 675) [Z: 56 WX: 1 WY: 0 FingerType: 2 Pressure : 0 Button: 0]
[   42.486186]: VRMI - Debug: F11 Packet
[   42.486198]: VRMI - Debug: Finger num: 0 (valid) (1074, 675) [Z: 56 WX: 1 WY: 0 FingerType: 2 Pressure : 0 Button: 0]
...
[   80.735186]: VRMI - Debug: F11 Packet
[  119.211702]: VRMI - Debug: Sleep
[  119.414268]: VRMI - Error: Failed to write sleep mode: -110.
[  119.616897]: VRMI - Error: rmi_driver_clear_irq_bits: Filaed to change enabled interrupts!
[  142.791488]: VRMI - Error: Failed to reset trackpad!
[  215.469095]: VRMI - Debug: Sleep
[  215.671858]: VRMI - Error: Failed to write sleep mode: -110.
[  215.873936]: VRMI - Error: smb_get_command_code: Failed to write mapping table data
[  215.873943]: VRMI - Error: rmi_driver_clear_irq_bits: Filaed to change enabled interrupts!
[  264.729684]: VRMI - Error: Failed to reset trackpad!
tvannoy commented 1 year ago

For what it's worth, XCode is complaining about "'IOPCIDevice' is deprecated: Use PCIDriverKit " in the VoodooSMBus project. I don't know if that could have anything to do with this bug.

imorda commented 1 year ago

Same stuff, Lenovo X1 Yoga Gen 3 (HW is really the same as in carbon gen 6)

tvannoy commented 1 year ago

Personally, I have moved on from my hackintosh now, but this issue was a showstopper for me. The alternative VoodooPS2Trackpad kext is painful to use. I figured this project was dead, but it appears that other discussions are happening now, so let's hope there is some progress on this. Unfortunately, I'm not familiar enough with kext development and don't have enough time to pursue fixing this bug.