"Change movement to scroll" doesn't work after locking Windows session and login back

[Killy]

XMBC Version: 2.20.5 (and few minor versions prior to that)
Installed or Portable version: installed
Windows Version: Windows 10 Pro 21H2 19044.3086
Mouse Information (brand/model): Logitech Trackman Marble T-BC21
Relevant Computer Information (CPU, RAM etc): CPU Intel Core i5-10500T; RAM 32,0 GB
Did the problem occur after an upgrade of XMBC? (If so, from what version?): can't remember where exactly it started, it is kind of intermittent, more consistent lately.
Did the problem occur after a Windows update/upgrade? (If so, from what version?): don't think so
How long have you used XMBC?: on this PC - since I've got it close to 2 years ago
What language and keyboard layout do you use in Windows?: System UI - English, layouts - US English QWERTY and Russian (strange, forum didn't accept Unicode here, replaced with question marks)

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).:

When I lock Windows session with Win+L and later log in back, "Change movement to scroll" feature stops working.
When toggled, it blocks regular mouse movement, but it doesn't perform the scroll it should do normally.
I have to either restart X-Mouse entirely or Disable/Enable it from tray menu to restore its function.

Occasionally, instead of completely non-functioning scroll, it does something weirder, like it scrolls intermittently, following some unknown logic. Probably derailed to some different broken state. After that it may also stop doing any scroll completely (broken state converges).
This may happen on different occasions, not only on session lock. But session lock is the most reproducible one.

Settings I use:

[Killy]

This still happens.
And usually, I have to restart XMBC twice before it starts to work again.
One restart isn't enough.

[phil]

Looks like I completely missed this one - as I usually reply even just to acknowledge it.
Its not something I have ever seen, but that's not really surprising as I don't really use change movement to scroll.
Quite a bit of change in the latest beta run in that area I think - so have you tried the latest beta per-chance? If not then of course nothing will have changed seeing as 2.20.5 is still the current "release". If its still a problem in the beta, and easily reproducible, maybe its something that will be discoverable/debug-able with some confidence.

[Killy]

Installed 2.21 beta 37. Will report once I notice the issue again.

The lack of dogfooding of the movement to scroll feature explains the lack of attention to other issues. This is really unfortunate for me.

[phil]

The lack of dogfooding of the movement to scroll feature explains the lack of attention to other issues. This is really unfortunate for me.

There is only one of me, XMBC is a hobby, XMBC is free.
I have a full time job and other responsibilities that take more time and priority I'm afraid.

I don't use change movement to scroll myself because I don't generally need it in my work flow.
If I removed everything form XMBC that I do not use, it wont do very much - maybe that would please you more because at least the little it did do would be well exercised?!

Of course, if you don't like it, you could do it yourself.... That's what I did and how XMBC started in the first place

[Killy]

Installed 2.21 beta 37. Will report once I notice the issue again.

Reporting back. The issue is still happening.

[phil]

OK I have tried to recreate this (on my Win10 dev box) but can't. It seems to work as expected, after locking/logging back in (several attempts at locking with WIN+L and leaving it various times before logging in).

Can you turn on debug logging and send me the log file next time it goes wrong?
NOTE: Debug logging will turn itself off when XMBC restarts, it *will* be better to setup a global hotkey to toggle debug logging ON/OFF, then after it happens, use that hotkey to toggle on debug logging (which will capture the previous ~200 lines of debug log to the file - which should be enough). Then send me the file (attach it here or by PM or by email).
Also, please note the time it goes wrong to help find the relevant section of the log file!

Regards,
Phil

[Killy]

Below are log fragments of repeating events when trying to use mouse-to-scroll.

TLDR, by doing a diff, I can see difference in following lines:

When mouse-to-scroll doesn't work properly:

Code: Select all

06-11-2024 22:17:56.146> MouseHookLLProc: Ignore button 7 down because sticky MTS 3 is set.

When mouse-to-scroll operates normally:

Code: Select all

08-11-2024 00:50:45.666> MouseHookLLProc: Ignoring mouse message injected by XMBC
08-11-2024 00:50:45.666> MouseHookLLProc: Passing original mouse message 0x0000020A through....

Longer log fragment when mouse-to-scroll doesn't work properly:

Code: Select all

06-11-2024 22:17:56.146> MouseHookLLProc: Ignore button 7 down because sticky MTS 3 is set.
06-11-2024 22:17:56.146> CSendInput::ProcessQueue: Finished sending 1 queue entries... (Flushed = 0)
06-11-2024 22:17:56.152> MTS: Multiplier = 1.000000
06-11-2024 22:17:56.160> MTS: Multiplier = 1.012500
06-11-2024 22:17:56.168> MTS: Multiplier = 1.025000
06-11-2024 22:17:56.168> MouseHookLLProc: Removing message 0x0200 (1136,804) from mouse hook queue as we have overridden it.
06-11-2024 22:17:56.176> MouseHookLLProc: MTS: Rows = -28.000000 Columns = -36.000000, Multiplier = 1.025000
06-11-2024 22:17:56.176> MouseHookLLProc: MTS: Lock = 1 start pt(1143,798) current pt(1136,806) Rows=-47.916, Columns=0.000
06-11-2024 22:17:56.176> SendInput - count = 1
06-11-2024 22:17:56.176> MovementToScroll result 0xFFFFFFFF time 0ms
06-11-2024 22:17:56.176> MouseHookLLProc: Removing message 0x0200 (1136,806) from mouse hook queue as we have overridden it.
06-11-2024 22:17:56.176> CSendInput::ProcessQueue: Starting to process 1 queue entries
06-11-2024 22:17:56.176> CSendInput::ProcessQueue: Sending 1 SIMULATED INPUTS
06-11-2024 22:17:56.176> MouseHookLLProc: MouseHookData: Msg=0x020A (WM_MOUSEWHEEL) Injected, X=1141, Y=797, Data=0xFF150000, Flags=0x00000001, Time=-2118555531, Info=0xAAE41109, Ptr=0xAAE41109, Layer=0
06-11-2024 22:17:56.176> MouseHookLLProc: Ignore button 7 down because sticky MTS 3 is set.
06-11-2024 22:17:56.176> CSendInput::ProcessQueue: Finished sending 1 queue entries... (Flushed = 0)
06-11-2024 22:17:56.183> MTS: Multiplier = 1.000000
06-11-2024 22:17:56.183> MouseHookLLProc: Removing message 0x0200 (1139,807) from mouse hook queue as we have overridden it.
06-11-2024 22:17:56.192> MTS: Multiplier = 1.012500
06-11-2024 22:17:56.192> MouseHookLLProc: Removing message 0x0200 (1140,803) from mouse hook queue as we have overridden it.
06-11-2024 22:17:56.200> MTS: Multiplier = 1.025000
06-11-2024 22:17:56.200> MouseHookLLProc: Removing message 0x0200 (1141,803) from mouse hook queue as we have overridden it.
06-11-2024 22:17:56.208> MouseHookLLProc: MTS: Rows = -27.000000 Columns = -11.000000, Multiplier = 1.025000
06-11-2024 22:17:56.208> MouseHookLLProc: MTS: Lock = 1 start pt(1143,798) current pt(1141,806) Rows=-30.631, Columns=0.000
06-11-2024 22:17:56.208> SendInput - count = 1
06-11-2024 22:17:56.208> MovementToScroll result 0xFFFFFFFF time 0ms
06-11-2024 22:17:56.208> MouseHookLLProc: Removing message 0x0200 (1141,806) from mouse hook queue as we have overridden it.
06-11-2024 22:17:56.208> CSendInput::ProcessQueue: Starting to process 1 queue entries
06-11-2024 22:17:56.208> CSendInput::ProcessQueue: Sending 1 SIMULATED INPUTS
06-11-2024 22:17:56.208> MouseHookLLProc: MouseHookData: Msg=0x020A (WM_MOUSEWHEEL) Injected, X=1141, Y=797, Data=0xFF6A0000, Flags=0x00000001, Time=-2118555500, Info=0xAAE41109, Ptr=0xAAE41109, Layer=0
06-11-2024 22:17:56.208> MouseHookLLProc: Ignore button 7 down because sticky MTS 3 is set.
06-11-2024 22:17:56.208> CSendInput::ProcessQueue: Finished sending 1 queue entries... (Flushed = 0)
06-11-2024 22:17:56.216> MTS: Multiplier = 1.000000
06-11-2024 22:17:56.223> MTS: Multiplier = 1.012500
06-11-2024 22:17:56.223> MouseHookLLProc: Removing message 0x0200 (1144,807) from mouse hook queue as we have overridden it.
06-11-2024 22:17:56.231> MTS: Multiplier = 1.025000
06-11-2024 22:17:56.231> MouseHookLLProc: Removing message 0x0200 (1148,807) from mouse hook queue as we have overridden it.
06-11-2024 22:17:56.239> MouseHookLLProc: MTS: Rows = -30.000000 Columns = 9.000000, Multiplier = 1.025000
06-11-2024 22:17:56.239> MouseHookLLProc: MTS: Lock = 1 start pt(1143,798) current pt(1147,808) Rows=-32.907, Columns=0.000
06-11-2024 22:17:56.239> SendInput - count = 1
06-11-2024 22:17:56.239> MovementToScroll result 0xFFFFFFFF time 0ms
06-11-2024 22:17:56.239> MouseHookLLProc: Removing message 0x0200 (1147,808) from mouse hook queue as we have overridden it.
06-11-2024 22:17:56.239> CSendInput::ProcessQueue: Starting to process 1 queue entries
06-11-2024 22:17:56.239> CSendInput::ProcessQueue: Sending 1 SIMULATED INPUTS
06-11-2024 22:17:56.240> MouseHookLLProc: MouseHookData: Msg=0x020A (WM_MOUSEWHEEL) Injected, X=1142, Y=800, Data=0xFF600000, Flags=0x00000001, Time=-2118555468, Info=0xAAE41109, Ptr=0xAAE41109, Layer=0

Longer log fragment when mouse-to-scroll operates normally:

Code: Select all

08-11-2024 00:50:45.666> MouseHookLLProc: Ignoring mouse message injected by XMBC
08-11-2024 00:50:45.666> MouseHookLLProc: Passing original mouse message 0x0000020A through....
08-11-2024 00:50:45.666> CSendInput::ProcessQueue: Finished sending 1 queue entries... (Flushed = 0)
08-11-2024 00:50:45.673> MTS: Multiplier = 1.000000
08-11-2024 00:50:45.681> MTS: Multiplier = 1.012500
08-11-2024 00:50:45.681> MouseHookLLProc: Removing message 0x0200 (1370,470) from mouse hook queue as we have overridden it.
08-11-2024 00:50:45.690> MouseHookLLProc: MTS: Rows = -12.000000 Columns = -8.000000, Multiplier = 1.012500
08-11-2024 00:50:45.690> MouseHookLLProc: MTS: Lock = 1 start pt(1374,466) current pt(1372,470) Rows=-14.785, Columns=0.000
08-11-2024 00:50:45.690> SendInput - count = 1
08-11-2024 00:50:45.690> MovementToScroll result 0xFFFFFFFF time 0ms
08-11-2024 00:50:45.690> MouseHookLLProc: Removing message 0x0200 (1372,470) from mouse hook queue as we have overridden it.
08-11-2024 00:50:45.690> CSendInput::ProcessQueue: Starting to process 1 queue entries
08-11-2024 00:50:45.690> CSendInput::ProcessQueue: Sending 1 SIMULATED INPUTS
08-11-2024 00:50:45.691> MouseHookLLProc: MouseHookData: Msg=0x020A (WM_MOUSEWHEEL) Injected, X=1372, Y=467, Data=0xFFBA0000, Flags=0x00000001, Time=-2022987562, Info=0x43781417, Ptr=0x43781417, Layer=0
08-11-2024 00:50:45.691> MouseHookLLProc: Ignoring mouse message injected by XMBC
08-11-2024 00:50:45.691> MouseHookLLProc: Passing original mouse message 0x0000020A through....
08-11-2024 00:50:45.692> CSendInput::ProcessQueue: Finished sending 1 queue entries... (Flushed = 0)
08-11-2024 00:50:45.698> MTS: Multiplier = 1.000000
08-11-2024 00:50:45.698> MouseHookLLProc: Removing message 0x0200 (1370,473) from mouse hook queue as we have overridden it.
08-11-2024 00:50:45.706> MTS: Multiplier = 1.012500
08-11-2024 00:50:45.706> MouseHookLLProc: Removing message 0x0200 (1371,475) from mouse hook queue as we have overridden it.
08-11-2024 00:50:45.713> MTS: Multiplier = 1.025000
08-11-2024 00:50:45.714> MouseHookLLProc: Removing message 0x0200 (1371,473) from mouse hook queue as we have overridden it.
08-11-2024 00:50:45.721> MouseHookLLProc: MTS: Rows = -31.000000 Columns = -13.000000, Multiplier = 1.025000
08-11-2024 00:50:45.721> MouseHookLLProc: MTS: Lock = 1 start pt(1374,466) current pt(1371,474) Rows=-35.317, Columns=0.000
08-11-2024 00:50:45.722> SendInput - count = 1
08-11-2024 00:50:45.722> MovementToScroll result 0xFFFFFFFF time 0ms
08-11-2024 00:50:45.722> MouseHookLLProc: Removing message 0x0200 (1371,474) from mouse hook queue as we have overridden it.
08-11-2024 00:50:45.722> CSendInput::ProcessQueue: Starting to process 1 queue entries
08-11-2024 00:50:45.722> CSendInput::ProcessQueue: Sending 1 SIMULATED INPUTS
08-11-2024 00:50:45.722> MouseHookLLProc: MouseHookData: Msg=0x020A (WM_MOUSEWHEEL) Injected, X=1372, Y=467, Data=0xFF510000, Flags=0x00000001, Time=-2022987531, Info=0x43781417, Ptr=0x43781417, Layer=0
08-11-2024 00:50:45.722> MouseHookLLProc: Ignoring mouse message injected by XMBC
08-11-2024 00:50:45.722> MouseHookLLProc: Passing original mouse message 0x0000020A through....
08-11-2024 00:50:45.723> CSendInput::ProcessQueue: Finished sending 1 queue entries... (Flushed = 0)
08-11-2024 00:50:45.730> MTS: Multiplier = 1.000000
08-11-2024 00:50:45.737> MTS: Multiplier = 1.012500
08-11-2024 00:50:45.738> MouseHookLLProc: Removing message 0x0200 (1372,471) from mouse hook queue as we have overridden it.
08-11-2024 00:50:45.746> MTS: Multiplier = 1.025000
08-11-2024 00:50:45.746> MouseHookLLProc: Removing message 0x0200 (1372,475) from mouse hook queue as we have overridden it.
08-11-2024 00:50:45.754> MouseHookLLProc: MTS: Rows = -31.000000 Columns = -9.000000, Multiplier = 1.025000
08-11-2024 00:50:45.754> MouseHookLLProc: MTS: Lock = 1 start pt(1374,466) current pt(1371,474) Rows=-33.914, Columns=0.000
08-11-2024 00:50:45.754> SendInput - count = 1
08-11-2024 00:50:45.754> MovementToScroll result 0xFFFFFFFF time 0ms
08-11-2024 00:50:45.754> MouseHookLLProc: Removing message 0x0200 (1371,474) from mouse hook queue as we have overridden it.
08-11-2024 00:50:45.754> CSendInput::ProcessQueue: Starting to process 1 queue entries
08-11-2024 00:50:45.754> CSendInput::ProcessQueue: Sending 1 SIMULATED INPUTS
08-11-2024 00:50:45.755> MouseHookLLProc: MouseHookData: Msg=0x020A (WM_MOUSEWHEEL) Injected, X=1372, Y=467, Data=0xFF5B0000, Flags=0x00000001, Time=-2022987500, Info=0x43781417, Ptr=0x43781417, Layer=0

If that's not enough, I'll try to get the log with the hotkey right after it happens next time.

[phil]

Hummm, so button 7 is MOUSEWHEEL UP....
So it is ignoring the mouse wheel up/down because the MTS (movement to scroll) button 3 (middle button) is down...
That suggests to me that you scrolled the wheel while the move to scroll was enabled - that shouldn't be a big deal... IF its you scrolling the wheel.. Of course it might be the simulated movement that being "ignored"...

But that shouldnt be the case, because it should not be blocking stuff XMBC itself has simulated..
The log when it works, says Ignoring mouse message injected by XMBC (which suggests it let it through undeterred)..

The question is why is the one that is "blocked" not detected as input that XMBC has injected. There is a data flag that XMBC sets so it knows not to intercept input that it, itself has simulated. It would appear, maybe that this has not been set correctly.

However, I need more log (you have truncated it too early) to see more.
Can you send the whole log file that contains the section 06-11-2024 22:17:56.146> MouseHookLLProc: Ignore button 7 down because sticky MTS 3 is set.
So I can see everything leading up to that (including the simulated scroll input and flags tht are set - they should be in the log file).
I suspect the problem may be the hook has been reset and the flag not updated or something (not sure how thats possible yet).

[Killy]

Reminder: Logitech Trackman Marble I use simply doesn't have a scroll wheel.

I sent you the new log from today via direct message.
I logged into my PC (16:19), noticed MTS doesn't work, activated the logging (16:21), tried to use MTS for a while, disabled and enabled XMBC via tray icon menu (this time it worked), used MTS normally for a while, deactivated logging.
What I see in the new log - corresponds with the previous logs.

Another note: sometimes in the past (not very often), it was breaking not 100%, some simulated scroll messages were passing through, not all of them might've been ignored. It was as if it tried to scroll, but quite erratically and with negligible result.

[phil]

At least if you don't have a scroll wheel, we know that it must be simulated input that blocked. It all makes sense, but what I don't understand is how its getting into that state in the first place. I will have a look through your logs later when I get a moment (hopefully).