Thinkpad P51 won't boot up w/ RMI [SOLVED]

AndyTQ commented 2 years ago

Hi,

I am having some trouble with getting VoodooRMI working on Thinkpad P51. I have spent 2 full days trying to figure out why it doesn't work, and it still does not work. It seems that there are successful working examples for P50 (and P52), but unfortunately I found 0 example of VoodooRMI working on Thinkpad P51, and someone else also mentioned that VoodooRMI does not work on Thinkpad P51 here.

I have tried the following already:

Set the boot order in plist config as described in the readme
Custom SSDT for IRQ patching
Check kextstat to see that all the kexts are loaded
Add vendor id and device id to VoodooSMBus kext's plist After trying all the solutions above, nothing occured. Trackpad does not work via RMI, and Trackpoint still does not work via RMI. (can work via PS2)

I then have tried loading VoodooRMI and VoodooSMBus manually, and use log show --last 1m | grep -i voodoo and it shows the following:

2022-04-23 17:15:47.878290-0400 0x615      Default     0x0                  105    0    kernelmanagerd: [com.apple.kernelmanagerd.logging:LoadRequestResolution] auxKC filesystem check: Kext com.1Revenger1.RMISMBus v1.0 in executable kext bundle com.1Revenger1.RMISMBus at /Users/andy/Desktop/VoodooRMI.kext/Contents/PlugIns/RMISMBus.kext found at /Users/andy/Desktop/VoodooRMI.kext/Contents/PlugIns/RMISMBus.kext
2022-04-23 17:15:47.878341-0400 0x615      Default     0x0                  105    0    kernelmanagerd: com.1Revenger1.RMISMBus exists in Optional(file:///Users/andy/Desktop/VoodooRMI.kext/Contents/PlugIns/RMISMBus.kext/), telling kernel to mark as available
2022-04-23 17:15:47.886871-0400 0x11a4     Default     0x0                  105    0    kernelmanagerd: Received kext load notification: com.1Revenger1.VoodooRMI
2022-04-23 17:15:47.887671-0400 0x11a3     Default     0x0                  0      0    kernel: (VoodooSMBus) VSMB - Debug: Publishing nub for slave device at address 0x2c
2022-04-23 17:15:47.887794-0400 0x11a3     Default     0x0                  0      0    kernel: (VoodooSMBus) VSMB - Debug: Publishing nub for slave device at address 0x15
2022-04-23 17:15:47.890774-0400 0x11a4     Default     0x0                  105    0    kernelmanagerd: Received kext load notification: de.leo-labs.VoodooSMBus
2022-04-23 17:15:53.089674-0400 0x11a7     Default     0x0                  0      0    kernel: (VoodooSMBus) VSMB - Error: Timeout waiting for bus to accept transfer request
2022-04-23 17:15:53.590881-0400 0x11a7     Default     0x0                  0      0    kernel: (VoodooSMBus) VSMB - Debug: Clearing status flags (02)
2022-04-23 17:15:53.792081-0400 0x11a7     Default     0x0                  0      0    kernel: (VoodooSMBus) VSMB - Error: Timeout waiting for bus to accept transfer request
2022-04-23 17:15:54.293275-0400 0x11a7     Default     0x0                  0      0    kernel: (VoodooSMBus) VSMB - Debug: Clearing status flags (02)
2022-04-23 17:15:54.494461-0400 0x11a7     Default     0x0                  0      0    kernel: (VoodooSMBus) VSMB - Error: Timeout waiting for bus to accept transfer request
2022-04-23 17:15:54.995666-0400 0x11a7     Default     0x0                  0      0    kernel: (VoodooSMBus) VSMB - Debug: Clearing status flags (02)
2022-04-23 17:15:55.196051-0400 0x11a7     Default     0x0                  0      0    kernel: (VoodooSMBus) VSMB - Error: Timeout waiting for bus to accept transfer request
2022-04-23 17:15:55.697250-0400 0x11a7     Default     0x0                  0      0    kernel: (VoodooSMBus) VSMB - Debug: Clearing status flags (02)
2022-04-23 17:15:55.898436-0400 0x11a7     Default     0x0                  0      0    kernel: (VoodooSMBus) VSMB - Error: Timeout waiting for bus to accept transfer request

Apparently in VoodooSMBus is telling me that there is a timeout that occurred. I am not sure about the cause of the timeout. But it seems to be called from commandSleep in VoodooSMBus/i2c_i801.cpp.

Currently, I am attempting to get into VoodooSMBus's dev branch and increased the timeout of adapter by 10 times (that's the only change) and recompiled the kext. I encountered some issue after loading the custom compiled kext with util, which says that

andy@Andys-MacBook-Pro Desktop % sudo kextload -vvvv ./VoodooRMI.kext
Executing: /usr/bin/kmutil load -p /Users/andy/Desktop/VoodooRMI.kext
Error Domain=KMErrorDomain Code=31 “Error occurred while building a collection:
  1: One or more binaries has an error which prevented linking. See other errors.
  2: Could not use ‘com.1Revenger1.RMISMBus’ because: Failed to bind ‘__ZN12RMITransport10gMetaClassE’ as could not find a kext with ‘com.1Revenger1.VoodooRMI’ bundle-id
com.1Revenger1.RMISMBus specific:
  1: Failed to bind ‘__ZN12RMITransport10gMetaClassE’ as could not find a kext with ‘com.1Revenger1.VoodooRMI’ bundle-id
” UserInfo={NSLocalizedDescription=Error occurred while building a collection:
  1: One or more binaries has an error which prevented linking. See other errors.
  2: Could not use ‘com.1Revenger1.RMISMBus’ because: Failed to bind ‘__ZN12RMITransport10gMetaClassE’ as could not find a kext with ‘com.1Revenger1.VoodooRMI’ bundle-id
com.1Revenger1.RMISMBus specific:
  1: Failed to bind ‘__ZN12RMITransport10gMetaClassE’ as could not find a kext with ‘com.1Revenger1.VoodooRMI’ bundle-id
}
andy@Andys-MacBook-Pro Desktop % sudo kextload -vvvv ./VoodooSMBus.kext
Executing: /usr/bin/kmutil load -p /Users/andy/Desktop/VoodooSMBus.kext
Error Domain=KMErrorDomain Code=71 “Kernel request failed: (libkern/kext) kext (kmod) start/stop routine failed (-603946985)” UserInfo={NSLocalizedDescription=Kernel request failed: (libkern/kext) kext (kmod) start/stop routine failed (-603946985)}

I am not sure if this error is related to my change, I might've also messed up the kext cache of the system. I will probably re-install the system, and then provide the IORegistry output and see if the newly compiled version would work. Currently IORegistry is also messed up (used to show RMISMBus under Nubs but not anymore)

And I am not even sure if increasing the timeout would help with this issue, so please give any additional guidance on what might cause the timeout. Thank you very much!

AndyTQ commented 2 years ago

I will use sudo dmesg | grep VRMI to get a more complete log next weekend, and post the IORegistry. Unfortunately I don't have much time this week and next week. I will provide more useful information next weekend.

AndyTQ commented 2 years ago

Update: I did a complete clean install again, and reloaded the RMI kexts, as well as setting vendor and device id in VoodooSMBus's plist. Now I am experiencing the EXACT same issue as https://github.com/VoodooSMBus/VoodooRMI/issues/143. Stuck at boot screen :/

AndyTQ commented 2 years ago

Here is another more complete log, during booting:

andy@andys-MacBook-Pro Desktop % log show --last 15m | grep -i voodoo   
2022-04-24 01:33:16.004766-0400 0xaa       Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.012485-0400 0x322      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.012500-0400 0x322      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.012606-0400 0x322      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.012765-0400 0x2c5      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.012874-0400 0x2c5      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.259461-0400 0x74       Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.262766-0400 0x74       Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.528239-0400 0x2d1      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.528308-0400 0x2e1      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.530505-0400 0x74       Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.563720-0400 0x2e1      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.563742-0400 0x2e1      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.564113-0400 0x2e1      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.564724-0400 0x2e1      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.564778-0400 0x2e1      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.772389-0400 0x388      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.772417-0400 0x388      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.772833-0400 0x388      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.773287-0400 0x388      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.773330-0400 0x388      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.855310-0400 0x74       Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.879442-0400 0x2c5      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:16.879511-0400 0x2c5      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:17.242038-0400 0x74       Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:17.316932-0400 0x74       Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:17.384719-0400 0x74       Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:17.384721-0400 0x74       Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:17.525374-0400 0x74       Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:17.759690-0400 0x74       Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:17.871037-0400 0x38b      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:17.871143-0400 0x38b      Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:17.902368-0400 0x74       Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:17.902879-0400 0x74       Default     0x0                  0      0    kernel: OSMetaClass: Kext me.kishorprins.VoodooInput class TrackpointDevice is a duplicate;kext de.leo-labs.VoodooSMBus already has a class by that name.
2022-04-24 01:33:17.902881-0400 0x74       Default     0x0                  0      0    kernel: Kext me.kishorprins.VoodooInput did not start (return code 0xdc00400a).
2022-04-24 01:33:17.902883-0400 0x74       Default     0x0                  0      0    kernel: Kext me.kishorprins.VoodooInput start failed (result 0xdc00400a).
2022-04-24 01:33:17.902885-0400 0x74       Default     0x0                  0      0    kernel: Kext me.kishorprins.VoodooInput failed to load (0xdc008017).
2022-04-24 01:33:17.902886-0400 0x74       Default     0x0                  0      0    kernel: Failed to load kext me.kishorprins.VoodooInput (error 0xdc008017).
2022-04-24 01:33:17.902915-0400 0x74       Default     0x0                  0      0    kernel: Couldn't alloc class "VoodooInput"
2022-04-24 01:33:17.902959-0400 0x74       Default     0x0                  0      0    kernel: OSMetaClass: Kext me.kishorprins.VoodooInput class TrackpointDevice is a duplicate;kext de.leo-labs.VoodooSMBus already has a class by that name.
2022-04-24 01:33:17.902961-0400 0x74       Default     0x0                  0      0    kernel: Kext me.kishorprins.VoodooInput did not start (return code 0xdc00400a).
2022-04-24 01:33:17.902963-0400 0x74       Default     0x0                  0      0    kernel: Kext me.kishorprins.VoodooInput start failed (result 0xdc00400a).
2022-04-24 01:33:17.902965-0400 0x74       Default     0x0                  0      0    kernel: Kext me.kishorprins.VoodooInput failed to load (0xdc008017).
2022-04-24 01:33:17.902967-0400 0x74       Default     0x0                  0      0    kernel: Failed to load kext me.kishorprins.VoodooInput (error 0xdc008017).
2022-04-24 01:33:17.902970-0400 0x74       Default     0x0                  0      0    kernel: Couldn't alloc class "VoodooInput"
2022-04-24 01:33:19.264385-0400 0x74       Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:19.264419-0400 0x74       Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:19.365710-0400 0x74       Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:19.365723-0400 0x74       Default     0x0                  0      0    kernel: (VoodooPS2Mouse) <compose failure [UUID]>
2022-04-24 01:33:23.577159-0400 0x2d4      Fault       0x0                  0      0    kernel: (IOHIDFamily) VoodooI2CMT2SimulatorDevice:0x10000030c Matching has vendor DeviceUsagePage : ff0c bundleIdentifier com.apple.AppleUserHIDDrivers ioclass AppleUserHIDEventService but transport and vendorID is missing
2022-04-24 01:33:23.719101-0400 0x63f      Fault       0x0                  0      0    kernel: (IOHIDFamily) VoodooI2CMT2SimulatorDevice:0x10000030c Matching has vendor DeviceUsagePage : ff0c bundleIdentifier com.apple.AppleUserHIDDrivers ioclass AppleUserHIDEventService but transport and vendorID is missing
2022-04-24 01:33:24.178959-0400 0x680      Default     0x0                  121    0    kernelmanagerd: Received kext load notification: as.acidanthera.voodoo.driver.PS2Controller
2022-04-24 01:33:24.179480-0400 0x680      Default     0x0                  121    0    kernelmanagerd: Received kext load notification: de.leo-labs.VoodooSMBus
2022-04-24 01:33:24.180608-0400 0x680      Default     0x0                  121    0    kernelmanagerd: Received kext load notification: as.acidanthera.voodoo.driver.PS2Trackpad
2022-04-24 01:33:24.181319-0400 0x680      Default     0x0                  121    0    kernelmanagerd: Received kext load notification: as.acidanthera.voodoo.driver.PS2Keyboard
2022-04-24 01:33:24.182146-0400 0x680      Default     0x0                  121    0    kernelmanagerd: Received kext load notification: as.acidanthera.voodoo.driver.PS2Mouse
2022-04-24 01:34:22.075243-0400 0x30a      Default     0x0                  0      0    kernel: busy timeout[0], (60s): 'VoodooSMBusDeviceNub'
2022-04-24 01:35:22.095287-0400 0x30a      Default     0x0                  0      0    kernel: busy timeout[1], (60s): 'VoodooSMBusDeviceNub'
2022-04-24 01:36:22.109392-0400 0x30a      Default     0x0                  0      0    kernel: busy timeout[2], (60s): 'VoodooSMBusDeviceNub'
2022-04-24 01:37:22.006349-0400 0x2e4      Default     0x0                  0      0    kernel: busy timeout[0], (240s): 'VoodooSMBusDeviceNub'
2022-04-24 01:37:22.030002-0400 0x398      Default     0x0                  104    0    configd: [com.apple.SystemConfiguration:InterfaceNamer]   MacBookPro14,3/AppleACPIPlatformExpert/PCI0@0/AppleACPIPCI/SBUS@1F,4/VoodooSMBusControllerDriver [1, 246396 ms]
2022-04-24 01:37:22.030014-0400 0x398      Default     0x0                  104    0    configd: [com.apple.SystemConfiguration:InterfaceNamer]   MacBookPro14,3/AppleACPIPlatformExpert/PCI0@0/AppleACPIPCI/SBUS@1F,4/VoodooSMBusControllerDriver/VoodooSMBusDeviceNub [!matched, 1, 246396 ms]
2022-04-24 01:37:22.123230-0400 0x30a      Default     0x0                  0      0    kernel: busy timeout[3], (60s): 'VoodooSMBusDeviceNub'
2022-04-24 01:41:22.020852-0400 0x2e4      Default     0x0                  0      0    kernel: busy timeout[1], (240s): 'VoodooSMBusDeviceNub'
2022-04-24 01:45:22.023780-0400 0x2e4      Default     0x0                  0      0    kernel: busy timeout[2], (240s): 'VoodooSMBusDeviceNub'

AndyTQ commented 2 years ago

Note that I also tried disabling SMCBatteryManager, but doesn't help. It seems that it's not the issue caused by battery manager..

AndyTQ commented 2 years ago

I might have messed up smbus kext version. will reopen if I didn't solve it after changing to the one from this repo.

AndyTQ commented 2 years ago

Apparently I still got problem. Since this issue is messy I created another issue at # 149.

VoodooSMBus / VoodooRMI

Thinkpad P51 won't boot up w/ RMI [SOLVED] #148