Noobsai / transparent-window-moving

GNOME Shell Extension. Makes window transparent while moving on the desktop.
https://extensions.gnome.org/extension/1446/transparent-window-moving/
GNU General Public License v3.0
39 stars 10 forks source link

[BUG] Certain applications become stuck in "transparent" mode when double-clicking them #13

Open Arcitec opened 2 years ago

Arcitec commented 2 years ago

Hi, first of all huge thanks again for this extension. It really makes the GNOME desktop look slick!

I've found a bug which I've suffered for a long time without realizing what caused it, until finally I tracked it down to Transparent Window Moving today.

The bug is as follows:

This issue doesn't happen if you just click-drag MPV's non-fullscreen window to move it. That works properly and goes transparent during move and then opaque afterwards, as intended.

It also doesn't happen if you use "F" to go into MPV's fullscreen instead of double-clicking.

The bug only happens when you double-click to fullscreen MPV.

After reading the source code of your extension, I suspect two potential areas where the bug could be:

  1. Perhaps the window_grab_end event never fires and therefore never restores the opacity.
  2. Perhaps the wrong opacity becomes stored in this._window_opacity which means that the opacity IS being "restored" but is being "restored" as a transparency.
  3. Perhaps even a combination of the two things: Double-clicking might register a new opacity, but the "window grab end" never fires so it never restores the opaque view, and then MPV gets "stuck" in transparent mode because all future moves triggers "window grab start" which registers the transparent opacity as the "normal one". This is probably what's happening.

This bug most likely affects more applications, but MPV is an easy one to test it in.

Until now, my personal workaround is to always use "F" on the keyboard to toggle MPV's fullscreen mode, since double-clicking confuses Transparent Window Moving.

If you need any more details or help, please let me know.

Noobsai commented 2 years ago

Thank you for detailed report. But I cannot reproduce it on my system. I tried the MPV on gnome-shell 41.5 (X11 and Wayland) and gnome-shell 42.3 (X11 only, cannot run the Wayland after update). I tried short and long animation time. Double-click works fine and opacity restores correctly. I prepared special brunch with debug messages , could you please replace the extension.js and catch the bug in a journal log:

journalctl -f -o cat GNOME_SHELL_EXTENSION_UUID=transparent-window-moving@noobsai.github.com

Perhaps this will help to investigate.

Also could you please set the animation time to 1.0 and perform this steps:

  1. Open any normal window (gnome-terminal, gnome-system-monitor)
  2. Grab the window and start moving it
  3. Wait until the window becomes a transparent
  4. Release, wait a bit, grab and moving it again before it becomes normal
  5. Release the window

The window should be normal at the end and log will be like:

[TWM] 1658948350486 window_grab_begin started pid=10238 op=255 -- step 2
[TWM] 1658948351489 window_grab_begin completed pid=10238 op=255 -- step 3
[TWM] 1658948358587 window_grab_end started pid=10238 op=255 -- step 4 after release
-- there is cancelled animation,  window_grab_end completed.  It's ok
[TWM] 1658948359072 window_grab_begin started pid=10238 op=255 -- step 4 after drag
[TWM] 1658948360082 window_grab_begin completed pid=10238 op=255 -- step 4 animation is ended
[TWM] 1658948363719 window_grab_end started pid=10238 op=255 -- step 5
[TWM] 1658948364724 window_grab_end completed pid=10238 op=255 -- step 5

Just interesting, this steps hits the bug on your system or not. Thanks!

Arcitec commented 2 years ago

Hi @Noobsai, thank you so much for creating a debug version!

So far, I have discovered a few things:

I will try the logging and other steps now!

Arcitec commented 2 years ago

Normal move of MPV window (not maximized/fullscreen): Works, as expected.

[TWM] 1658973949039 window_grab_begin started pid=1279430 op=255
[TWM] 1658973949040 window_grab_begin completed pid=1279430 op=255
[TWM] 1658973949129 window_grab_begin completed pid=1279430 op=255
[TWM] 1658973949813 window_grab_end started pid=1279430 op=255
[TWM] 1658973949813 window_grab_end completed pid=1279430 op=255
[TWM] 1658973949917 window_grab_end completed pid=1279430 op=undefined

Double-clicked MPV window to go fullscreen: Opacity stuck afterwards.

[TWM] 1658973973410 window_grab_begin started pid=1279430 op=255
[TWM] 1658973973411 window_grab_begin completed pid=1279430 op=255
[TWM] 1658973973493 window_grab_begin completed pid=1279430 op=255
[TWM] 1658973973501 window_grab_end started pid=1279430 op=255
[TWM] 1658973973501 window_grab_end completed pid=1279430 op=255
[TWM] 1658973973572 window_grab_begin started pid=1279430 op=234
[TWM] 1658973973573 window_grab_begin completed pid=1279430 op=234
[TWM] 1658973973658 window_grab_end started pid=1279430 op=234
[TWM] 1658973973659 window_grab_end completed pid=1279430 op=234
[TWM] 1658973973790 window_grab_end completed pid=1279430 op=undefined

My setting in TWM is 0.10 animation time, and 127 opacity to make it really transparent for testing purposes, by the way. So it's interesting that it got stuck at 234 opacity.

This suggests to me that the opacity is being saved in an in-between state.

I'll resume with the other animation time tests now!

Arcitec commented 2 years ago

New test with 1.00 animation time, and 127 opacity:

Here is the test with gnome-terminal, grabbing it with 1 second animation time and releasing and re-grabbing it repeatedly while the animation hasn't finished, basically grabbing it again when it's still transparent.

[TWM] 1658974179273 window_grab_begin started pid=1279980 op=255
[TWM] 1658974179516 window_grab_end started pid=1279980 op=255
[TWM] 1658974179688 window_grab_begin started pid=1279980 op=255
[TWM] 1658974179941 window_grab_end started pid=1279980 op=255
[TWM] 1658974180264 window_grab_begin started pid=1279980 op=255
[TWM] 1658974180534 window_grab_end started pid=1279980 op=255
[TWM] 1658974180807 window_grab_begin started pid=1279980 op=255
[TWM] 1658974181052 window_grab_end started pid=1279980 op=255
[TWM] 1658974181338 window_grab_begin started pid=1279980 op=255
[TWM] 1658974181613 window_grab_end started pid=1279980 op=255
[TWM] 1658974181875 window_grab_begin started pid=1279980 op=255
[TWM] 1658974182135 window_grab_end started pid=1279980 op=255
[TWM] 1658974182357 window_grab_begin started pid=1279980 op=255
[TWM] 1658974182652 window_grab_end started pid=1279980 op=255
[TWM] 1658974182909 window_grab_begin started pid=1279980 op=255
[TWM] 1658974183143 window_grab_end started pid=1279980 op=255
[TWM] 1658974183995 window_grab_end completed pid=1279980 op=255
[TWM] 1658974185139 window_grab_begin started pid=1279980 op=255
[TWM] 1658974185425 window_grab_end started pid=1279980 op=255
[TWM] 1658974186276 window_grab_end completed pid=1279980 op=255

I tried a few others, like Files, System Monitor, etc, and they all returned to 255 at the end properly.

Arcitec commented 2 years ago

Here's another test: Opacity 40, Animation time 1.0 seconds, and double-clicking on MPV:

[TWM] 1658974430444 window_grab_begin started pid=1281417 op=255
[TWM] 1658974430445 window_grab_begin completed pid=1281417 op=255
[TWM] 1658974430513 window_grab_end started pid=1281417 op=255
[TWM] 1658974430514 window_grab_end completed pid=1281417 op=255
[TWM] 1658974430599 window_grab_begin started pid=1281417 op=233
[TWM] 1658974430600 window_grab_begin completed pid=1281417 op=233
[TWM] 1658974430686 window_grab_end started pid=1281417 op=233
[TWM] 1658974430686 window_grab_end completed pid=1281417 op=233
[TWM] 1658974431541 window_grab_end completed pid=1281417 op=undefined

Interesting that opacity got stuck at 233 now (when TWM was set to 50 opacity) instead of 234 (when TWM was set to 127 opacity).

So let's try setting TWM to 240 opacity and 1.00 seconds and see what happens:

[TWM] 1658974539160 window_grab_begin started pid=1281689 op=255
[TWM] 1658974539161 window_grab_begin completed pid=1281689 op=255
[TWM] 1658974539224 window_grab_end started pid=1281689 op=255
[TWM] 1658974539225 window_grab_end completed pid=1281689 op=255
[TWM] 1658974539278 window_grab_begin started pid=1281689 op=253
[TWM] 1658974539279 window_grab_begin completed pid=1281689 op=253
[TWM] 1658974539378 window_grab_end started pid=1281689 op=253
[TWM] 1658974539378 window_grab_end completed pid=1281689 op=253
[TWM] 1658974540255 window_grab_end completed pid=1281689 op=undefined

Interesting indeed, so now it got stuck at 253.

This means that the target opacity in TWM affects what opacity MPV gets stuck at.

Now let's see if the animation time is also a factor, so we try target opacity 20, animation time 1 second:

[TWM] 1658974628569 window_grab_begin started pid=1282042 op=255
[TWM] 1658974628571 window_grab_begin completed pid=1282042 op=255
[TWM] 1658974628614 window_grab_end started pid=1282042 op=255
[TWM] 1658974628614 window_grab_end completed pid=1282042 op=255
[TWM] 1658974628725 window_grab_begin started pid=1282042 op=240
[TWM] 1658974628726 window_grab_begin completed pid=1282042 op=240
[TWM] 1658974628823 window_grab_end started pid=1282042 op=240
[TWM] 1658974628824 window_grab_end completed pid=1282042 op=240
[TWM] 1658974629685 window_grab_end completed pid=1282042 op=undefined

Let's repeat the opacity 20, animation 1 second test:

[TWM] 1658974646423 window_grab_begin started pid=1282257 op=255
[TWM] 1658974646424 window_grab_begin completed pid=1282257 op=255
[TWM] 1658974646497 window_grab_end started pid=1282257 op=255
[TWM] 1658974646498 window_grab_end completed pid=1282257 op=255
[TWM] 1658974646578 window_grab_begin started pid=1282257 op=232
[TWM] 1658974646578 window_grab_begin completed pid=1282257 op=232
[TWM] 1658974646687 window_grab_end started pid=1282257 op=232
[TWM] 1658974646688 window_grab_end completed pid=1282257 op=232
[TWM] 1658974647553 window_grab_end completed pid=1282257 op=undefined

Interesting... so it varies every time, it's not a static target.

Let's now try opacity 20, animation time 0.1 seconds:

[TWM] 1658974699661 window_grab_begin started pid=1282400 op=255
[TWM] 1658974699663 window_grab_begin completed pid=1282400 op=255
[TWM] 1658974699745 window_grab_end started pid=1282400 op=255
[TWM] 1658974699746 window_grab_end completed pid=1282400 op=255
[TWM] 1658974699817 window_grab_begin started pid=1282400 op=217
[TWM] 1658974699818 window_grab_begin completed pid=1282400 op=217
[TWM] 1658974699899 window_grab_begin completed pid=1282400 op=217
[TWM] 1658974699915 window_grab_end started pid=1282400 op=217
[TWM] 1658974699915 window_grab_end completed pid=1282400 op=217
[TWM] 1658974700027 window_grab_end completed pid=1282400 op=undefined

Ok, conclusion:

Arcitec commented 2 years ago

By the way, regarding this:

"I tried the MPV on gnome-shell 41.5 (X11 and Wayland) and gnome-shell 42.3 (X11 only, cannot run the Wayland after update)."

Did you mean that Wayland doesn't work in GNOME 42.3 for you?

Or do you mean that mpv doesn't work in Wayland for you?

If mpv doesn't launch for you on Wayland, then building it from source works. Their main branch has had a lot of Wayland fixes for NVIDIA. If you're on Fedora I can provide instructions how to make a fresh RPM file.

 

Edit: I was running MPV built from Git on May 30th, so I re-built it now on July 28th from the latest Git. The opacity still gets stuck.

Arcitec commented 2 years ago

I just had an idea of what might be happening here:

Perhaps MPV briefly stops listening to the "set window opacity" commands while it is changing display mode to "specialized full-screen"?

Like this:

This is just a theory, but basically, since the logs look pretty good, my best theory is that mpv is ignoring the opacity commands during the full-screen transition.

I guess it would be helpful to output the window handle id/address of the thing being animated. That way we can see if the ID changes after mpv goes full-screen. The ID might still remain the same though, and the issue is probably that the window simply ignores all the other opacity commands from TWM during the transition to full-screen. I don't know if this is possible (for windows to ignore things).

It's my best guess since the logs seem like TWM IS TRYING to set opacity back to 255. But when we look at the next "grab start" event, the window is stuck in transparent mode. And it doesn't look like TWM requested the opacity that it got stuck at, since we can see that TWM tried to set a 255 before the next grab event. So perhaps certain apps like mpv and maybe others use some kinda "full-screen trick" which ignores opacity commands during the switch to full-screen.

PS: I have a cold and am in bed but when I wake up I will run a test to see if MPV listens to opacity commands after exiting full-screen. Will be interesting to see if it also ignores "move opacity" commands when moving the normal window after it has become stuck. Sorry if I repeated myself/rambled, but I am too tired to think at the moment. Goodnight. 😴😊

Arcitec commented 2 years ago

Yes, after exiting fullscreen again, with a stuck opacity, and then dragging to move the normal non-maximized window, will apply the move-opacity as intended. So the MPV window listens to opacity after having left fullscreen.

This, together with the fact that the logs show that TWM TRIED to set Opacity 255 but failed to do it, solidifies my theory that MPV (and other apps using same techniques for entering fullscreen on Wayland) simply ignores the "set opacity" commands from TWM for a brief moment while it's entering fullscreen.

This is most likely what is happening:

Another, similar possibility:

Some possible ideas for solutions:

Let's take this example "Double-clicked MPV window to go fullscreen: Opacity stuck afterwards." again, and look at the data and proposal:

Double-click happens here:
[TWM] 1658973973410 window_grab_begin started pid=1279430 op=255
[TWM] 1658973973411 window_grab_begin completed pid=1279430 op=255
[TWM] 1658973973493 window_grab_begin completed pid=1279430 op=255

Double-click ends here:
[TWM] 1658973973501 window_grab_end started pid=1279430 op=255
[TWM] 1658973973501 window_grab_end completed pid=1279430 op=255

Now TWM should look and say 1658973973501 (grab-end completion time) - 1658973973493 (grab-start
completion time) = 8... Literally 8 milliseconds between start and end events.

This is where TWM has failed to apply the "opacity 255" after the end event...
...in fact, TWM may still be busy animating the "grab begin transparency" when it's
trying to set the "grab end transparency", so perhaps it's a conflict between two
event animations both running at the same time?

Anyway, perhaps do this:

"on end completion, if time difference < 100 milliseconds: Start a 500ms timer,
which does a sanity check after 0.5 second has passed:
- First check the opacity we TRIED to set the app to (255), and check what the
app actually has (234 in this case).
- If they differ, send 1 more "set opacity" event to "fix" the broken window."
Arcitec commented 2 years ago

By the way this is a low-priority bug for me, so don't feel any stress about it. Sure it's annoying but the workaround of pressing "F" to fullscreen instead of double-click is a decent workaround.

Arcitec commented 2 years ago

I just remembered this issue again today and just want to say: Don't worry about it. Enjoy your summer! :D

Noobsai commented 2 years ago

Hi, how are you doing?

Did you mean that Wayland doesn't work in GNOME 42.3 for you?

After update to 42.3 the option GNOME on Wayland is missing at the Login screen. So I tested 41.5 Wayland.

Look at this log:

Here's another test: Opacity 40, Animation time 1.0 seconds, and double-clicking on MPV:

[TWM] 1658974430444 window_grab_begin started pid=1281417 op=255
[TWM] 1658974430445 window_grab_begin completed pid=1281417 op=255
[TWM] 1658974430513 window_grab_end started pid=1281417 op=255
[TWM] 1658974430514 window_grab_end completed pid=1281417 op=255
[TWM] 1658974430599 window_grab_begin started pid=1281417 op=233
[TWM] 1658974430600 window_grab_begin completed pid=1281417 op=233
[TWM] 1658974430686 window_grab_end started pid=1281417 op=233
[TWM] 1658974430686 window_grab_end completed pid=1281417 op=233
[TWM] 1658974431541 window_grab_end completed pid=1281417 op=undefined

First, there is something wrong with events timestamps. See first two rows. If you set 1 second, the difference between started and completed events should be about >1000 ms. You have 1 ms. It's very strange.

Second, look at the latest two lines. The same event window_grab_end completed triggered twice.

There is my log for animation 1 sec. Difference between timestamps quite more then 1000 ms

[TWM] 1659728432017 window_grab_begin started pid=56637 op=255
[TWM] 1659728433019 window_grab_begin completed pid=56637 op=255
[TWM] 1659728434252 window_grab_end started pid=56637 op=255
[TWM] 1659728435255 window_grab_end completed pid=56637 op=255

There is double-click on MPV --border=no on Wayland with target opacity 40 and animation time 1 sec

[TWM] 1659741566973 window_grab_begin started pid=6434 op=255
[TWM] 1659741566995 window_grab_end started pid=6434 op=255
[TWM] 1659741567092 window_grab_begin started pid=6434 op=255
[TWM] 1659741567204 window_grab_end started pid=6434 op=255
[TWM] 1659741568212 window_grab_end completed pid=6434 op=255

There is only one completed event in my log because the rest have been cancelled.

And I still cannot reproduce this bug. I don't know where is bug actually, in my code or upstream. My main theory - the function onComplete called before end of animation for some reason. Maybe it affected only 42.3 Wayland, but I cannot check this case. I will run Wayland on 42.3 later after fix system performance on 42.3 X11 (I don't know why but it's lagging for me). For a while I have made the special version for you. I just removed preserving an original opacity of window. Replace the extension.js

Good luck!