XMBC dehooks and/or freezes after away for a long time

x64 Replacement/Alternative to Microsoft's IntelliMouse application.
Forum rules
Please read the forum rules before posting for the first time.
The more information you can provide, the quicker and more accurately someone can help.
NOTE: To reduce spam, new users can not post links, files or images until they have at least 4 posts.
Post Reply
gillius
New User
Posts: 7
Joined: Fri May 22, 2020 2:54 pm

XMBC dehooks and/or freezes after away for a long time

Post by gillius »

XMBC Version: 2.19.1
Windows Version: Windows 10 build 18363
Mouse Information (brand/model): Logitech G5
Relevant Computer Information (CPU, RAM etc): i5-8365U, 16GB
Did the problem occur after an upgrade of XMBC? (If so, from what version?): maybe
Did the problem occur after a Windows update/upgrade? (If so, from what version?): no
How long have you used XMBC?: many years
What language and keyboard layout do you use in Windows?: US English

Clear description of the problem - try and include as much information as possible, including what button and mappings you are having problems with (if applicable).:

Got a new laptop and installed 2.19.1 latest version on it. Copied my Roaming profile over from old machine, so XBMC settings did come over, and everything works, except when computer is locked for awhile, XBMC zombies. The process is still running, but the system tray icon is there only about half the time. If it is there, it shows red X as if it is disabled; re-enabling does not work. If the tray icon is gone, launching XMBC does not work. The only way to fix it is to end task the process from task manager, then it is possible to restart XMBC (otherwise XMBC shortcut appears to try to re-awaken the zombie XBMC). I've tried several different hook timeout settings. It only happens when my machine is locked for awhile. Maybe the trigger is when the monitors finally power off, or maybe it's the screensaver, but just simply locking and unlocking does not trigger it.

Here are the logs. At 13:38 is when I returned back to the machine to unlock it.

Code: Select all

*******************************************************************************************************************************************
22-05-2020 09:19:06.607> X-Mouse Button Control v2.19.1 (x64) Startup. Commandline '/notportable'
22-05-2020 09:19:06.609> Running in high integrity mode (0x00003000)
22-05-2020 09:19:06.622> Loaded 3 application specific profiles (3 normal and 0 custom window).
22-05-2020 09:19:06.623> Running on Microsoft Windows 10 Enterprise Edition (build 18363), 64-bit, Hook Timeout: 1000 ms
22-05-2020 09:19:06.623> Startup folder: 'C:\Program Files\Highresolution Enterprises\X-Mouse Button Control\'
22-05-2020 09:19:06.623> Settings (and log) folder: 'C:\Users\n9944491\AppData\Roaming\Highresolution Enterprises\XMouseButtonControl\'
22-05-2020 09:19:06.634> Warning: SendSPI(3, 0) called but the thread is not running!
22-05-2020 09:19:06.737> Using keyboard language 0x04090409
22-05-2020 09:43:51.417> CMyMessageWnd::OnSetup   -   Opening setup dialog.
22-05-2020 09:43:51.450> Loaded 3 application specific profiles (3 normal and 0 custom window).
22-05-2020 09:44:00.874> CMyMessageWnd::OnSetup   -   Setup dialog closed.
22-05-2020 09:44:00.878> Loaded 3 application specific profiles (3 normal and 0 custom window).
22-05-2020 09:45:10.200> Warning: SendSPI(3, 0) called but the thread is not running!
22-05-2020 09:45:10.303> Using keyboard language 0x04090409
22-05-2020 09:47:44.977> CMyMessageWnd::OnSetup   -   Opening setup dialog.
22-05-2020 09:47:44.998> Loaded 3 application specific profiles (3 normal and 0 custom window).
22-05-2020 09:56:36.981> CMyMessageWnd::OnSetup   -   Setup dialog closed.
22-05-2020 09:56:36.985> Loaded 3 application specific profiles (3 normal and 0 custom window).
22-05-2020 11:57:23.754> OnTaskBarCreated: Recreating systray icon
22-05-2020 13:38:09.407> OnTaskBarCreated: Recreating systray icon
22-05-2020 13:38:15.992> OnTaskBarCreated: Recreating systray icon
22-05-2020 13:38:20.245> SPIThread did not exit in a timely fashion!
22-05-2020 13:38:41.502> OnTaskBarCreated: Recreating systray icon

*******************************************************************************************************************************************
User avatar
phil
Site Admin
Posts: 7664
Joined: Sun Apr 06, 2003 11:12 pm

Re: XMBC dehooks and/or freezes after away for a long time

Post by phil »

Known issue - 2.19.2 out soon will fix it...
A search should have revealed at least this :):
https://forums.highrez.co.uk/viewtopic. ... 5fb2517c11
--[ Phil ]--
--[ Administrator & XMBC Author ]--
Logitech G9/G604/M720/MX518, Microsoft Intellimouse, Trust 16341 BT Mouse
Windows 10 x64, AMD Ryzen 5900x, MSI x570 Tomahawk, 32GB DDR4,
nVidia RTX 2070s, Evo 970 1Tb NVME, 2x2TB WD Black (RAID1)
gillius
New User
Posts: 7
Joined: Fri May 22, 2020 2:54 pm

Re: XMBC dehooks and/or freezes after away for a long time

Post by gillius »

Thanks Phil for the quick response. I did try a search and scanned the list of recent posts. Clearly I did not do that well enough, because that post is pretty clear. I searched the titles on the XMBC page and probably used the word "hang" instead and searched for "lock". If it helps I did find the docs around hook timeout so I had something to try, and log files :).

I did see in the 2.19.1 changelog about sleeping and I'm not sleeping but I see what you said in the other post it also triggers other times. I couldn't find an old 2.19.0 link for download though to try. I will wait for 2.19.2.

And BTW, thanks for this tool I have used it many years to map my middle mouse to double click. I got hooked on it since Logitech DOS TSR driver in the 90s and use it on every computer since. And since XMBC > Logitech software and works everywhere, I use XBMC! I'm also a donator!
User avatar
phil
Site Admin
Posts: 7664
Joined: Sun Apr 06, 2003 11:12 pm

Re: XMBC dehooks and/or freezes after away for a long time

Post by phil »

No problem ... 2.19 suffers too - although slightly differently.
Im aiming to get 2.19.2 out this weekend - but it will depend on (B) - should be good for tomorrow fingers crossed - basically its all done and all I have to do it push the right buttons to make it live to all - so not too much trouble :)
--[ Phil ]--
--[ Administrator & XMBC Author ]--
Logitech G9/G604/M720/MX518, Microsoft Intellimouse, Trust 16341 BT Mouse
Windows 10 x64, AMD Ryzen 5900x, MSI x570 Tomahawk, 32GB DDR4,
nVidia RTX 2070s, Evo 970 1Tb NVME, 2x2TB WD Black (RAID1)
gillius
New User
Posts: 7
Joined: Fri May 22, 2020 2:54 pm

Re: XMBC dehooks and/or freezes after away for a long time

Post by gillius »

Hi phil,

I still see this happening on 2.19.2. If you prefer I post in the other thread you linked (4253) I can move my post there...

It looks like there is some more logging in 2.19.2. Here's the log file before I end task then restart. The log ends with a message about timeout waiting for the hook thread.

Code: Select all

*******************************************************************************************************************************************
28-05-2020 13:31:59.016> X-Mouse Button Control v2.19.2 (x64) Startup. Commandline '/notportable'
28-05-2020 13:31:59.017> Running in high integrity mode (0x00003000)
28-05-2020 13:31:59.032> Loaded 3 application specific profiles (3 normal and 0 custom window).
28-05-2020 13:31:59.032> Running on Microsoft Windows 10 Enterprise Edition (build 18363), 64-bit, Hook Timeout: 250 ms
28-05-2020 13:31:59.032> Warning: Low Level Hook Timeout is low. If you have problems try increasing this value.
28-05-2020 13:31:59.032> Startup folder: 'C:\Program Files\Highresolution Enterprises\X-Mouse Button Control\'
28-05-2020 13:31:59.032> Settings (and log) folder: 'C:\Users\n9944491\AppData\Roaming\Highresolution Enterprises\XMouseButtonControl\'
28-05-2020 13:31:59.147> HookThreadProc[0xD20]: Using keyboard language 0x04090409
28-05-2020 17:43:12.585> OnTaskBarCreated: Recreating systray icon
28-05-2020 17:43:38.934> Reinstall mouse hook on resume is enabled. Resetting hooks on session logon...
28-05-2020 17:43:40.869> The lock for 'HookThread Clean-up' took 1922ms to release!
28-05-2020 17:43:41.171> HookThreadProc[0x42E8]: Using keyboard language 0x04090409
28-05-2020 17:43:46.553> OnTaskBarCreated: Recreating systray icon
28-05-2020 18:10:16.849> OnTaskBarCreated: Recreating systray icon
28-05-2020 18:15:37.859> OnTaskBarCreated: Recreating systray icon
28-05-2020 18:15:40.467> OnTaskBarCreated: Recreating systray icon
28-05-2020 18:19:31.560> OnTaskBarCreated: Recreating systray icon
28-05-2020 18:19:34.151> OnTaskBarCreated: Recreating systray icon
28-05-2020 21:02:47.018> OnTaskBarCreated: Recreating systray icon
28-05-2020 21:02:50.655> OnTaskBarCreated: Recreating systray icon
28-05-2020 21:02:55.102> Reinstall mouse hook on resume is enabled. Resetting hooks on session logon...
28-05-2020 21:02:56.748> The lock for 'HookThread Clean-up' took 1625ms to release!
28-05-2020 21:02:57.004> HookThreadProc[0x449C]: Using keyboard language 0x04090409
28-05-2020 21:03:14.324> OnTaskBarCreated: Recreating systray icon
28-05-2020 23:20:49.403> OnTaskBarCreated: Recreating systray icon
29-05-2020 01:34:23.582> OnTaskBarCreated: Recreating systray icon
29-05-2020 01:34:26.682> OnTaskBarCreated: Recreating systray icon
29-05-2020 09:15:34.946> OnTaskBarCreated: Recreating systray icon
29-05-2020 09:15:37.457> OnTaskBarCreated: Recreating systray icon
29-05-2020 09:15:43.258> Reinstall mouse hook on resume is enabled. Resetting hooks on session logon...
29-05-2020 09:15:44.941> The lock for 'HookThread Clean-up' took 1593ms to release!
29-05-2020 09:15:45.119> HookThreadProc[0x196C]: Using keyboard language 0x04090409
29-05-2020 09:15:56.959> OnTaskBarCreated: Recreating systray icon
29-05-2020 13:49:30.618> OnTaskBarCreated: Recreating systray icon
29-05-2020 13:56:35.235> OnTaskBarCreated: Recreating systray icon
29-05-2020 13:56:40.572> OnTaskBarCreated: Recreating systray icon
29-05-2020 13:56:55.364> Reinstall mouse hook on resume is enabled. Resetting hooks on session logon...
29-05-2020 13:56:57.232> The lock for 'HookThread Clean-up' took 1843ms to release!
29-05-2020 13:56:57.442> HookThreadProc[0x3BA4]: Using keyboard language 0x04090409
29-05-2020 13:57:28.883> OnTaskBarCreated: Recreating systray icon
01-06-2020 09:07:02.400> OnTaskBarCreated: Recreating systray icon
01-06-2020 09:07:06.947> Reinstall mouse hook on resume is enabled. Resetting hooks on session logon...
01-06-2020 09:07:09.009> The lock for 'HookThread Clean-up' took 2047ms to release!
01-06-2020 09:07:14.014> SetMouseHook: Timeout waiting for hook thread [0x2F4] to start and install hooks. This is not good!
01-06-2020 09:07:14.014> SetMouseHook failed!
User avatar
phil
Site Admin
Posts: 7664
Joined: Sun Apr 06, 2003 11:12 pm

Re: XMBC dehooks and/or freezes after away for a long time

Post by phil »

Oh wow...
So this is the first report of a problem post 2.19.2. Everyone else (so far) has reported it is now working - so lets leave this one here in his thread :).

OK. Several things to do.... The first and most important (to try and track this down) is to enable even more (targetted) logging - there is actually lots more logging specifically for this problem that can be turned on - but you will have to manually do that by editing XMBCSettings.xml (it should be an easy edit in notepad or any text editor)....
  1. Open the settings folder - (To do this, you can HOLD CTRL and left click once on the XMBC icon - that opens the folder in explorer)...
  2. Close (fully exit) XMBC using the exit option on the context menu on the XMBC icon
  3. Open XMBCSettings.xml in a text editor
  4. Search for <Logging Disable="false" Thread="false" />
  5. Change to <Logging Disable="false" Thread="true" />
  6. Save and reload XMBC.
  7. Reproduce the problem and send me that log - it will have more (but targeted) logging.
Once you have captured and sent me that log, there are some things you can do that *may* reduce/remove the problem as a workaround - but lets get that logging first because clearly fixing is better than working around!

EDIT: I wonder, are you seeing this as regularly? I suspect the mitigations I put in may have reduced the occurrences but perhaps the "relatively" low spec mobile CPU is taking slightly longer and things are still timing out (esp. since the 2042ms - it shouldn't be taking >2 seconds to remove the hook - it gives up if it takes that long and once it gives up that it... Maybe on the mobile CPU's that's a little optimistic - all my machines are higher spec - so that *may* make a difference. Hopefully the extra logging will give me precise detail as to what has taken too long and with a bit of luck, why.

EDIT2: Does the XMBC icon still exist now though (and does it respond - can you double click it to open the settings window/right click it to show the context menu)? Because in theory although it gives up hooking, it shouldn't be freezing/locking up/crashing, the rest should still be working - as in the GUI should open even if the hooks are not there now?

Regards,
Phil
--[ Phil ]--
--[ Administrator & XMBC Author ]--
Logitech G9/G604/M720/MX518, Microsoft Intellimouse, Trust 16341 BT Mouse
Windows 10 x64, AMD Ryzen 5900x, MSI x570 Tomahawk, 32GB DDR4,
nVidia RTX 2070s, Evo 970 1Tb NVME, 2x2TB WD Black (RAID1)
gillius
New User
Posts: 7
Joined: Fri May 22, 2020 2:54 pm

Re: XMBC dehooks and/or freezes after away for a long time

Post by gillius »

The log file captured is typical of how often it happens, it looks like it's once every other day or so. It does seem to be less frequent than 2.19.1 which sometimes happened more than once a day. But session lock/unlock is not a very frequent operation.

When it happens, before in 2.19.1 I would see no icon, or icon with red X. Now when it happens I see icon with no red X but the icon is not responsive to right click or double click.

I updated the XML I found in my roaming AppData folder: <Logging Disable="false" /> to <Logging Disable="false" Thread="true"/>

I will report back if/when the issue happens again.

As for the laptop spec... I am a software developer, and it is always a sore point for me. Believe it or not my last laptop was a 7th gen i5 U series, which is actually only dual core. When I heard they got brand new laptops at my company I requested to be front of the line... And it's an 8th gen almost lowest spec Dell... At least it's quad core... :roll: And it is a corporate-IT set up laptop so who knows what crazy they've done to the image.

That said on my old laptop I never had this issue. In fact all of the years (maybe decade?) I've been using XBMC I've not seen this. But I was using probably a 3 year old version on that laptop (corporate firewall blocks the default update functionality).

Here are the logs from the subsequent start:

Code: Select all

*******************************************************************************************************************************************
02-06-2020 09:08:22.761> X-Mouse Button Control v2.19.2 (x64) Startup. Commandline '/notportable'
02-06-2020 09:08:22.762> Running in high integrity mode (0x00003000)
02-06-2020 09:08:22.765> Loaded 3 application specific profiles (3 normal and 0 custom window).
02-06-2020 09:08:22.765> Enabling thread debugging
02-06-2020 09:08:22.765> NewApplicationSettings: SPIThread is not initialised.
02-06-2020 09:08:22.765> Running on Microsoft Windows 10 Enterprise Edition (build 18363), 64-bit, Hook Timeout: 250 ms
02-06-2020 09:08:22.765> Warning: Low Level Hook Timeout is low. If you have problems try increasing this value.
02-06-2020 09:08:22.765> Startup folder: 'C:\Program Files\Highresolution Enterprises\X-Mouse Button Control\'
02-06-2020 09:08:22.765> Settings (and log) folder: 'C:\Users\n9944491\AppData\Roaming\Highresolution Enterprises\XMouseButtonControl\'
02-06-2020 09:08:22.765> SetMouseHook: Started timer thread [0x2C8]...
02-06-2020 09:08:22.765> SetMouseHook: Started hook thread [0x2C8]...
02-06-2020 09:08:22.765> HookThreadProc[0x6DEC]: Hook thread starting...
02-06-2020 09:08:22.775> SPI Thread [0x304] has started.
02-06-2020 09:08:22.776> SendInput Thread [0x308] has started.
02-06-2020 09:08:22.776> SendInputThread: Running thread ID 0x6A54.
02-06-2020 09:08:22.776> SPIThread[0x6734]: Running thread...
02-06-2020 09:08:22.776> HookThreadProc[0x6DEC]: Using keyboard language 0x04090409
02-06-2020 09:08:22.776> HookThreadProc[0x6DEC]: Installing low level mouse hook
02-06-2020 09:08:22.776> HookThreadProc[0x6DEC]: Installing low level key hook (for layer modifier keys)
02-06-2020 09:08:22.776> SetMouseHook: Started hook thread [0x2CC]...
User avatar
phil
Site Admin
Posts: 7664
Joined: Sun Apr 06, 2003 11:12 pm

Re: XMBC dehooks and/or freezes after away for a long time

Post by phil »

I confess, the laptop CPU issue was a bit of a stab in the dark, a recent CPU should be absolutely fine given that it has worked for years... But of course XMBC has changed - and maybe the two combined have put something over the edge... I'm only speculating because I have never seen this - but all of my machines are high spec (even the laptops). Having said that, I have an old Surface 2 Pro which is not so high specced and I havn't been able to reproduce on that (or VM's) either... So its probably not the CPU but something else.

I hope the logs will give some more ideas (it should log all the thread creation, and destruction paths to give some idea which thread is sticking around more than it should - and hopefully why!). Of course, turning on any debug will impact the order of things somewhat - knowing my luck It will probably turn out to be two threads waiting on writing to the log file (that would be a bit ironic).

Regards,
Phil
--[ Phil ]--
--[ Administrator & XMBC Author ]--
Logitech G9/G604/M720/MX518, Microsoft Intellimouse, Trust 16341 BT Mouse
Windows 10 x64, AMD Ryzen 5900x, MSI x570 Tomahawk, 32GB DDR4,
nVidia RTX 2070s, Evo 970 1Tb NVME, 2x2TB WD Black (RAID1)
gillius
New User
Posts: 7
Joined: Fri May 22, 2020 2:54 pm

Re: XMBC dehooks and/or freezes after away for a long time

Post by gillius »

It could be possible that performance has some impact. The issue reproduced again. It seems only to happen when my monitors are off or shift... Windows 10 has this weird thing (on all of my computers) where it thinks you unplugged all monitors and plugged them back in. On my laptop it's even worse. When I unlock the computer it normally takes 5-6 seconds before all of the application windows have finished re-rendering, moving, and re-sizing and the desktop is usable -- all of the apps switch from 1.0x DPI mode to 2.0x DPI mode on the 4k monitor and everything including task bar shifts over. So during this time there could be really high CPU usage... I've never seen this happen if I just lock and immediately unlock. It only seems to happen when the monitors turn off after some time (and for whatever reason, switch user does this even without the delay).

In this case I was simply switching users (and in this case the monitors all get messed up again).

Here are the XMBC logs:

Code: Select all

*******************************************************************************************************************************************
02-06-2020 09:08:22.761> X-Mouse Button Control v2.19.2 (x64) Startup. Commandline '/notportable'
02-06-2020 09:08:22.762> Running in high integrity mode (0x00003000)
02-06-2020 09:08:22.765> Loaded 3 application specific profiles (3 normal and 0 custom window).
02-06-2020 09:08:22.765> Enabling thread debugging
02-06-2020 09:08:22.765> NewApplicationSettings: SPIThread is not initialised.
02-06-2020 09:08:22.765> Running on Microsoft Windows 10 Enterprise Edition (build 18363), 64-bit, Hook Timeout: 250 ms
02-06-2020 09:08:22.765> Warning: Low Level Hook Timeout is low. If you have problems try increasing this value.
02-06-2020 09:08:22.765> Startup folder: 'C:\Program Files\Highresolution Enterprises\X-Mouse Button Control\'
02-06-2020 09:08:22.765> Settings (and log) folder: 'C:\Users\n9944491\AppData\Roaming\Highresolution Enterprises\XMouseButtonControl\'
02-06-2020 09:08:22.765> SetMouseHook: Started timer thread [0x2C8]...
02-06-2020 09:08:22.765> SetMouseHook: Started hook thread [0x2C8]...
02-06-2020 09:08:22.765> HookThreadProc[0x6DEC]: Hook thread starting...
02-06-2020 09:08:22.775> SPI Thread [0x304] has started.
02-06-2020 09:08:22.776> SendInput Thread [0x308] has started.
02-06-2020 09:08:22.776> SendInputThread: Running thread ID 0x6A54.
02-06-2020 09:08:22.776> SPIThread[0x6734]: Running thread...
02-06-2020 09:08:22.776> HookThreadProc[0x6DEC]: Using keyboard language 0x04090409
02-06-2020 09:08:22.776> HookThreadProc[0x6DEC]: Installing low level mouse hook
02-06-2020 09:08:22.776> HookThreadProc[0x6DEC]: Installing low level key hook (for layer modifier keys)
02-06-2020 09:08:22.776> SetMouseHook: Started hook thread [0x2CC]...
02-06-2020 09:17:09.612> Reinstall mouse hook on resume is enabled. Resetting hooks on session logon...
02-06-2020 09:17:09.613> Requesting timer thread [0x2C8] (ID 0x4658) to exit...
02-06-2020 09:17:09.617> Removing any active XMBCHook Timers...
02-06-2020 09:17:09.620> Timer thread [0x2C8] exited successfully.
02-06-2020 09:17:09.620> Requesting hook thread [0x2CC] (ID 0x6DEC) to exit...
02-06-2020 09:17:09.628> HookThreadProc[0x6DEC]: Exit requested...
02-06-2020 09:17:09.628> HookThreadProc[0x6DEC]: Finished the message loop. Cleaning up...
02-06-2020 09:17:09.628> RemoveHooks: Removing hooks...
02-06-2020 09:17:09.630> HookThreadProc[0x6DEC]: Removed hooks...
02-06-2020 09:17:09.630> Requesting SendInput Thread [0x308] (ID 0x6A54) to exit...
02-06-2020 09:17:09.631> SendInputThread: Received exit request...
02-06-2020 09:17:09.631> SendInputThread: Exiting SendInput thread.
02-06-2020 09:17:09.635> SendInput thread [0x308] exited successfully.
02-06-2020 09:17:09.636> Requesting SPI Thread [0x304] (ID 0x6734) to exit...
02-06-2020 09:17:10.013> SPIThread[0x6734]: Received exit request...
02-06-2020 09:17:10.013> SPIThread[0x6734]: Exiting thread.
02-06-2020 09:17:10.014> SPI thread 0x304 exited successfully.
02-06-2020 09:17:10.015> HookThreadProc[0x6DEC]: Finished cleaning up.
02-06-2020 09:17:10.016> Hook thread [0x2CC] exited successfully.
02-06-2020 09:17:10.036> RemoveMouseHook thread took 406ms
02-06-2020 09:17:10.036> Hooks have been removed...
02-06-2020 09:17:10.036> SetMouseHook: Started timer thread [0x61C]...
02-06-2020 09:17:10.036> SetMouseHook: Started hook thread [0x61C]...
02-06-2020 09:17:10.037> HookThreadProc[0x4098]: Hook thread starting...
02-06-2020 09:17:10.102> SPI Thread [0x324] has started.
02-06-2020 09:17:10.102> SendInput Thread [0x2CC] has started.
02-06-2020 09:17:10.102> SPIThread[0x63D8]: Running thread...
02-06-2020 09:17:10.103> SendInputThread: Running thread ID 0x6FAC.
02-06-2020 09:17:10.104> HookThreadProc[0x4098]: Using keyboard language 0x04090409
02-06-2020 09:17:10.104> HookThreadProc[0x4098]: Installing low level mouse hook
02-06-2020 09:17:10.104> HookThreadProc[0x4098]: Installing low level key hook (for layer modifier keys)
02-06-2020 09:17:10.104> SetMouseHook: Started hook thread [0x62C]...
02-06-2020 09:17:10.104> Hooks have been re-added.
02-06-2020 09:20:50.771> OnTaskBarCreated: Recreating systray icon
02-06-2020 12:12:46.939> Reinstall mouse hook on resume is enabled. Resetting hooks on session logon...
02-06-2020 12:12:46.942> Requesting timer thread [0x61C] (ID 0x62C0) to exit...
02-06-2020 12:12:46.949> Removing any active XMBCHook Timers...
02-06-2020 12:12:46.954> Timer thread [0x61C] exited successfully.
02-06-2020 12:12:46.954> Requesting hook thread [0x62C] (ID 0x4098) to exit...
02-06-2020 12:12:46.956> HookThreadProc[0x4098]: Exit requested...
02-06-2020 12:12:46.956> HookThreadProc[0x4098]: Finished the message loop. Cleaning up...
02-06-2020 12:12:46.956> RemoveHooks: Removing hooks...
02-06-2020 12:12:46.959> HookThreadProc[0x4098]: Removed hooks...
02-06-2020 12:12:46.960> Requesting SendInput Thread [0x2CC] (ID 0x6FAC) to exit...
02-06-2020 12:12:46.966> SendInputThread: Received exit request...
02-06-2020 12:12:46.966> SendInputThread: Exiting SendInput thread.
02-06-2020 12:12:46.970> SendInput thread [0x2CC] exited successfully.
02-06-2020 12:12:46.973> Requesting SPI Thread [0x324] (ID 0x63D8) to exit...
02-06-2020 12:12:47.809> The lock for 'CCursors::DestroyCursors' took 922ms to release!
02-06-2020 12:12:47.809> The lock for 'CCursors::DestroyCursors' took 922ms to release!
02-06-2020 12:12:48.975> SPI thread [0x324] did not exit in a timely fashion  - terminating it...
02-06-2020 12:12:48.978> HookThreadProc[0x4098]: Finished cleaning up.
02-06-2020 12:12:48.979> The lock for 'HookThread Clean-up' took 2031ms to release!
02-06-2020 12:12:48.980> Hook thread [0x62C] exited successfully.
02-06-2020 12:12:48.993> RemoveMouseHook thread took 2046ms
02-06-2020 12:12:48.994> Hooks have been removed...
02-06-2020 12:12:48.994> SetMouseHook: Started timer thread [0x704]...
02-06-2020 12:12:48.994> SetMouseHook: Started hook thread [0x704]...
02-06-2020 12:12:48.995> HookThreadProc[0x7074]: Hook thread starting...
02-06-2020 12:12:53.994> SetMouseHook: Timeout waiting for hook thread [0x708] to start and install hooks. This is not good!
02-06-2020 12:12:53.994> SetMouseHook failed!

*******************************************************************************************************************************************
User avatar
phil
Site Admin
Posts: 7664
Joined: Sun Apr 06, 2003 11:12 pm

Re: XMBC dehooks and/or freezes after away for a long time

Post by phil »

OK, Thanks, I need to take some time to digest that properly... Initial thoughts are its not good that both threads have the same ID 0x704 - that may well be a bug in the logging though (if thats the case, a real pain to figure out whats going on). I will have to look in detail at it, with the code in front of me - so maybe later tonight or tomorrow I'll get back to you.

In the meantime, there is a new setting in 2.19.2 on the advanced tab (I think)... Reset mouse hooks when resuming from sleep. If you turn that off, if shouldn't re-hook when resuming from sleep (and I believe from locked). That's the work around I mentioned earlier. Of course it would be good to figure it out and fix it, but at least in the meantime that should sort your daily lockup out until I get a bit further - I may have to send you some interim test builds too if I can grasp what is going on and propose a fix (if you don't mind).

Regards
Phil
--[ Phil ]--
--[ Administrator & XMBC Author ]--
Logitech G9/G604/M720/MX518, Microsoft Intellimouse, Trust 16341 BT Mouse
Windows 10 x64, AMD Ryzen 5900x, MSI x570 Tomahawk, 32GB DDR4,
nVidia RTX 2070s, Evo 970 1Tb NVME, 2x2TB WD Black (RAID1)
gillius
New User
Posts: 7
Joined: Fri May 22, 2020 2:54 pm

Re: XMBC dehooks and/or freezes after away for a long time

Post by gillius »

I will try the option to not reset mouse hooks. What is the purpose behind resetting mouse hooks, if it is not required? BTW, my laptop itself never sleeps, only the monitors. I only lock and unlock (or in the one-off case earlier today, switch user).

The issue reproduced again tonight. I didn't see anything extra useful in these logs, but if it helps they are at the bottom of this post.

I don't have any issues in testing out any versions you might have. I'm grateful for the tool and any support you are willing to give, especially since I seem to be in the minority. I am also running XBMC on my desktop, and I have never seen the issue there. It's an i5-6600k Windows 10. Although I never lock/unlock that machine but I probably do in practice because I remote desktop into it, which I think counts as an unlock.

Code: Select all

*******************************************************************************************************************************************
02-06-2020 12:16:29.257> X-Mouse Button Control v2.19.2 (x64) Startup. Commandline '/notportable'
02-06-2020 12:16:29.257> Running in high integrity mode (0x00003000)
02-06-2020 12:16:29.257> Loaded 3 application specific profiles (3 normal and 0 custom window).
02-06-2020 12:16:29.257> Enabling thread debugging
02-06-2020 12:16:29.257> NewApplicationSettings: SPIThread is not initialised.
02-06-2020 12:16:29.257> Running on Microsoft Windows 10 Enterprise Edition (build 18363), 64-bit, Hook Timeout: 250 ms
02-06-2020 12:16:29.257> Warning: Low Level Hook Timeout is low. If you have problems try increasing this value.
02-06-2020 12:16:29.257> Startup folder: 'C:\Program Files\Highresolution Enterprises\X-Mouse Button Control\'
02-06-2020 12:16:29.257> Settings (and log) folder: 'C:\Users\n9944491\AppData\Roaming\Highresolution Enterprises\XMouseButtonControl\'
02-06-2020 12:16:29.257> SetMouseHook: Started timer thread [0x2BC]...
02-06-2020 12:16:29.257> SetMouseHook: Started hook thread [0x2BC]...
02-06-2020 12:16:29.257> HookThreadProc[0x6EBC]: Hook thread starting...
02-06-2020 12:16:29.270> SPI Thread [0x2F4] has started.
02-06-2020 12:16:29.270> SendInput Thread [0x2F8] has started.
02-06-2020 12:16:29.270> SPIThread[0x27D4]: Running thread...
02-06-2020 12:16:29.270> SendInputThread: Running thread ID 0x6080.
02-06-2020 12:16:29.270> HookThreadProc[0x6EBC]: Using keyboard language 0x04090409
02-06-2020 12:16:29.270> HookThreadProc[0x6EBC]: Installing low level mouse hook
02-06-2020 12:16:29.270> HookThreadProc[0x6EBC]: Installing low level key hook (for layer modifier keys)
02-06-2020 12:16:29.270> SetMouseHook: Started hook thread [0x2C4]...
02-06-2020 12:17:28.644> OnTaskBarCreated: Recreating systray icon
02-06-2020 16:04:41.368> Reinstall mouse hook on resume is enabled. Resetting hooks on session logon...
02-06-2020 16:04:41.369> Requesting timer thread [0x2BC] (ID 0x64A8) to exit...
02-06-2020 16:04:41.376> Removing any active XMBCHook Timers...
02-06-2020 16:04:41.378> Timer thread [0x2BC] exited successfully.
02-06-2020 16:04:41.379> Requesting hook thread [0x2C4] (ID 0x6EBC) to exit...
02-06-2020 16:04:41.379> HookThreadProc[0x6EBC]: Exit requested...
02-06-2020 16:04:41.380> HookThreadProc[0x6EBC]: Finished the message loop. Cleaning up...
02-06-2020 16:04:41.380> RemoveHooks: Removing hooks...
02-06-2020 16:04:41.380> HookThreadProc[0x6EBC]: Removed hooks...
02-06-2020 16:04:41.380> Requesting SendInput Thread [0x2F8] (ID 0x6080) to exit...
02-06-2020 16:04:41.381> SendInputThread: Received exit request...
02-06-2020 16:04:41.381> SendInputThread: Exiting SendInput thread.
02-06-2020 16:04:41.382> SendInput thread [0x2F8] exited successfully.
02-06-2020 16:04:41.382> Requesting SPI Thread [0x2F4] (ID 0x27D4) to exit...
02-06-2020 16:04:41.680> SPIThread[0x27D4]: Received exit request...
02-06-2020 16:04:41.680> SPIThread[0x27D4]: Exiting thread.
02-06-2020 16:04:41.681> SPI thread 0x2F4 exited successfully.
02-06-2020 16:04:41.682> HookThreadProc[0x6EBC]: Finished cleaning up.
02-06-2020 16:04:41.683> Hook thread [0x2C4] exited successfully.
02-06-2020 16:04:41.687> RemoveMouseHook thread took 313ms
02-06-2020 16:04:41.687> Hooks have been removed...
02-06-2020 16:04:41.717> SetMouseHook: Started timer thread [0x7E8]...
02-06-2020 16:04:41.718> SetMouseHook: Started hook thread [0x7E8]...
02-06-2020 16:04:41.718> HookThreadProc[0x1550]: Hook thread starting...
02-06-2020 16:04:41.779> SPI Thread [0x2F8] has started.
02-06-2020 16:04:41.779> SendInput Thread [0x6C4] has started.
02-06-2020 16:04:41.779> SPIThread[0x794C]: Running thread...
02-06-2020 16:04:41.779> SendInputThread: Running thread ID 0x50F0.
02-06-2020 16:04:41.883> HookThreadProc[0x1550]: Using keyboard language 0x04090409
02-06-2020 16:04:41.884> HookThreadProc[0x1550]: Installing low level mouse hook
02-06-2020 16:04:41.884> HookThreadProc[0x1550]: Installing low level key hook (for layer modifier keys)
02-06-2020 16:04:41.884> SetMouseHook: Started hook thread [0x6BC]...
02-06-2020 16:04:41.884> Hooks have been re-added.
02-06-2020 23:15:05.542> OnTaskBarCreated: Recreating systray icon
02-06-2020 23:18:34.243> Reinstall mouse hook on resume is enabled. Resetting hooks on session logon...
02-06-2020 23:18:34.244> Requesting timer thread [0x7E8] (ID 0x3D90) to exit...
02-06-2020 23:18:34.244> Removing any active XMBCHook Timers...
02-06-2020 23:18:34.254> Timer thread [0x7E8] exited successfully.
02-06-2020 23:18:34.254> Requesting hook thread [0x6BC] (ID 0x1550) to exit...
02-06-2020 23:18:34.298> HookThreadProc[0x1550]: Exit requested...
02-06-2020 23:18:34.298> HookThreadProc[0x1550]: Finished the message loop. Cleaning up...
02-06-2020 23:18:34.298> RemoveHooks: Removing hooks...
02-06-2020 23:18:34.311> HookThreadProc[0x1550]: Removed hooks...
02-06-2020 23:18:34.314> Requesting SendInput Thread [0x6C4] (ID 0x50F0) to exit...
02-06-2020 23:18:34.320> SendInputThread: Received exit request...
02-06-2020 23:18:34.320> SendInputThread: Exiting SendInput thread.
02-06-2020 23:18:34.323> SendInput thread [0x6C4] exited successfully.
02-06-2020 23:18:34.324> Requesting SPI Thread [0x2F8] (ID 0x794C) to exit...
02-06-2020 23:18:36.326> SPI thread [0x2F8] did not exit in a timely fashion  - terminating it...
02-06-2020 23:18:36.909> The lock for 'CCursors::DestroyCursors' took 578ms to release!
02-06-2020 23:18:36.909> HookThreadProc[0x1550]: Finished cleaning up.
02-06-2020 23:18:36.909> The lock for 'HookThread Clean-up' took 2609ms to release!
02-06-2020 23:18:36.909> Hook thread [0x6BC] exited successfully.
02-06-2020 23:18:36.927> RemoveMouseHook thread took 2656ms
02-06-2020 23:18:36.927> Hooks have been removed...
02-06-2020 23:18:36.932> SetMouseHook: Started timer thread [0x2BC]...
02-06-2020 23:18:36.932> SetMouseHook: Started hook thread [0x2BC]...
02-06-2020 23:18:36.932> HookThreadProc[0x7078]: Hook thread starting...
02-06-2020 23:18:41.933> SetMouseHook: Timeout waiting for hook thread [0x6E8] to start and install hooks. This is not good!
02-06-2020 23:18:41.933> SetMouseHook failed!

*******************************************************************************************************************************************
gillius
New User
Posts: 7
Joined: Fri May 22, 2020 2:54 pm

Re: XMBC dehooks and/or freezes after away for a long time

Post by gillius »

I'm not sure of any advantage I might be missing from the reset mouse hooks when resuming feature but so far for me there have been no issues since I turned that off.
User avatar
phil
Site Admin
Posts: 7664
Joined: Sun Apr 06, 2003 11:12 pm

Re: XMBC dehooks and/or freezes after away for a long time

Post by phil »

There was a time when the hooks could get lost during sleep - that is why that was put in originally...
If it works with it off (and the hooks don't get lost) then great - its more efficient not to re-hook. That's why I made the option to turn it off available in 2.19.2 but I would of course like to figure out what is wrong with the re-hook because it did (and should) work!

I haven't got around to looking at it any more yet!
--[ Phil ]--
--[ Administrator & XMBC Author ]--
Logitech G9/G604/M720/MX518, Microsoft Intellimouse, Trust 16341 BT Mouse
Windows 10 x64, AMD Ryzen 5900x, MSI x570 Tomahawk, 32GB DDR4,
nVidia RTX 2070s, Evo 970 1Tb NVME, 2x2TB WD Black (RAID1)
Post Reply