WarmUpTill / SceneSwitcher

An automation tool for OBS Studio
https://obsproject.com/forum/resources/automatic-scene-switching.395/
GNU General Public License v2.0
984 stars 78 forks source link

Deadlock while handling callbacks #11

Closed notr1ch closed 4 years ago

notr1ch commented 5 years ago

While investigating a report of OBS UI freezing, I noticed this plugin was causing a deadlock. Perhaps order of locking is incorrect somewhere.

Main (UI) Thread:

.  0  Id: 5a20.46d4 Suspend: 0 Teb: 000007ff`fffdd000 Unfrozen
 # RetAddr           : Args to Child                                                           : Call Site
00 00000000`77477c56 : 00000000`07f69700 ffffffff`fffffffe 00000000`1e01f1c0 00000000`1b502180 : ntdll!ZwWaitForKeyedEvent+0xa
01 000007fe`e6bb8795 : 000007fe`e6bb8510 00000000`00000000 00000000`03313190 00000000`07f6a100 : ntdll!RtlAcquireSRWLockExclusive+0x106
02 000007fe`ca1b6d29 : 00000000`00000000 00000000`0000000f 00000000`00000002 00000000`03313190 : msvcp140!mtx_do_lock+0x91 [f:\dd\vctools\crt\crtw32\stdcpp\thr\mutex.c @ 100] 
03 00000001`3feeaed0 : 00000000`00000002 00000000`00000008 00000000`02fc6700 00000000`00000000 : advanced_scene_switcher+0x16d29
04 00000001`3ffeb5cf : 00000000`00000000 00000000`02f481e0 00000000`0031b6b0 00000000`08271760 : obs64!OBSStudioAPI::on_event+0x60
05 00000001`4004536c : 00000000`0360b010 00000000`00000000 00000000`02f481e0 000007fe`cc4551b6 : obs64!OBSBasic::TransitionStopped+0xdf
06 000007fe`cc453f0e : 00000000`02f481e0 00000000`080b6840 00000000`02f481e0 00000000`0031fb60 : obs64!OBSBasic::qt_static_metacall+0x5fc
07 000007fe`cd05e6c1 : 00000000`02fce570 00000000`02fa4f80 00000000`00000012 00000000`00000000 : Qt5Core!QObject::event+0xde
08 000007fe`cd03890d : 00000000`00154400 00000000`00154400 00000000`02f481e0 00000000`080b6840 : Qt5Widgets!QWidget::event+0x16e1
09 000007fe`cd037767 : 00000000`0012d110 00000000`0031bce0 00000000`080b6840 00000000`081caeb0 : Qt5Widgets!QApplicationPrivate::notify_helper+0x17d
0a 000007fe`cc42c2c9 : 00000000`080b6800 00000000`02f481e0 00000000`080b6840 00000000`7737f5fb : Qt5Widgets!QApplication::notify+0x1b47
0b 000007fe`cc42e888 : 00000000`0031c3e8 00000000`00000000 00000000`080b6840 00000000`0000fffe : Qt5Core!QCoreApplication::notifyInternal2+0xb9
0c 000007fe`ca27aa8f : 00000000`0012d140 00000000`00000000 00000000`0017c870 00000000`0031c420 : Qt5Core!QCoreApplicationPrivate::sendPostedEvents+0x228
0d 000007fe`cc4782e6 : 00000000`00000000 00000000`00000401 00000000`0031c529 00000000`00000001 : qwindows!qt_plugin_query_metadata+0x1b5f
0e 00000000`77389bd1 : 00000000`00000000 00000000`00000038 00000000`0031c638 00000000`00000004 : Qt5Core!QEventDispatcherWin32::processEvents+0xce6
0f 00000000`773898da : 00000000`0031c708 000007fe`cc477ef0 00000000`00000024 00000000`00a2b7e0 : user32!UserCallWinProcCheckWow+0x1ad
10 000007fe`cc477baf : 00000000`00000000 00000000`00000001 000007fe`cc477ef0 00000000`00177438 : user32!DispatchMessageWorker+0x3b5
11 000007fe`ca27aa69 : 00000001`400b1a01 00000000`00000000 00000000`00154400 00000000`03558900 : Qt5Core!QEventDispatcherWin32::processEvents+0x5af
12 000007fe`cc427442 : 00000000`00000000 00000000`00000014 00000000`0012d110 00000000`0012d110 : qwindows!qt_plugin_query_metadata+0x1b39
13 000007fe`cc42ab3a : 00000000`0015efc0 00000000`00000000 00000000`0031fd80 000007fe`cc527f98 : Qt5Core!QEventLoop::exec+0x1f2
14 00000001`3fee3a4c : 00000001`4015966a 00000000`00000000 00000000`0031fd80 00000000`0014a8a0 : Qt5Core!QCoreApplication::exec+0x15a
15 00000001`3fee60a0 : 00000000`00000000 00000000`00149c40 00000000`00000000 00000000`0013a6a0 : obs64!run_program+0x75c
16 00000001`4005c084 : 00000000`0012f280 00000000`00000000 00000000`00000000 00000000`00000000 : obs64!main+0x670
17 00000001`4005b162 : 00000000`00000001 00000000`00000000 00000000`00000000 01d53bda`661180e5 : obs64!WinMain+0x154
18 00000000`772659ed : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : obs64!__scrt_common_main_seh+0x106
19 00000000`7749b371 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : kernel32!BaseThreadInitThunk+0xd
1a 00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x1d

An advanced-scene-switcher thread:

  43  Id: 5a20.5520 Suspend: 0 Teb: 000007ff`fff34000 Unfrozen
 # RetAddr           : Args to Child                                                           : Call Site
00 000007fe`fd3e10ac : 00000000`1db519e0 00000000`1db51640 00000000`1db52220 000007fe`cc2887f1 : ntdll!ZwWaitForSingleObject+0xa
01 000007fe`cc288bbb : 00000000`ffffffff 00000000`1db51640 00000000`00000000 00000000`00004220 : KERNELBASE!WaitForSingleObjectEx+0x79
02 000007fe`cc281600 : 00000000`00000001 00000000`1db51640 00000000`1db51641 00000000`1db51640 : Qt5Core!QWaitCondition::wait+0x9b
03 000007fe`cc43373d : 00000000`1db51641 00000000`00000001 00000000`1909ed80 00000000`00000000 : Qt5Core!QSemaphore::acquire+0x70
04 000007fe`cc433ce4 : 00000000`1db51640 00000000`00000004 00000000`00000004 00000000`1909f600 : Qt5Core!QMetaMethod::invoke+0x78d
05 00000001`3feea4d7 : 00000006`0000611c 00720054`00000000 00000000`00154400 00480065`00670061 : Qt5Core!QMetaObject::invokeMethod+0x594
06 000007fe`ca1bb4cf : 00000000`07fa1d00 00000000`07fa1d20 000007fe`ca1a0000 00000000`07fb0ce0 : obs64!OBSStudioAPI::obs_frontend_set_current_scene+0x327
07 000007fe`ca1bbc8f : 00000000`0031ead8 00000000`0031ead8 00000000`079cd800 00000000`08309110 : advanced_scene_switcher+0x1b4cf
08 000007fe`ca1bb619 : 00000000`0031ead8 00000000`00000000 00000000`00000000 00000000`00000000 : advanced_scene_switcher+0x1bc8f
09 000007fe`cc8782dd : 00000000`00000000 00000000`00000000 00000000`079cd800 00000000`00000000 : advanced_scene_switcher+0x1b619
0a 00000000`772659ed : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ucrtbase!crt_at_quick_exit+0x7d
0b 00000000`7749b371 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : kernel32!BaseThreadInitThunk+0xd
0c 00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x1d

The scene switcher seems to be trying to change the scene via obs_frontend_set_current_scene from a thread, which is then blocked trying to pass a signal to the UI, presumably because the main thread is in the middle of running callbacks for a completed scene transition. The scene switcher is blocking in the transition callback for reasons unknown, possibly waiting on the change scene thread to complete, resulting in a deadlock.

WarmUpTill commented 5 years ago

Thanks for the report! I havn't touched the code for a while, so I am a bit surprised about this.

Do you have more information regarding the reproduction? Does this issue occur frequently?

slidedrum commented 4 years ago

Hello, I am not sure if I am having the exact same issue, but in the interest of not starting a duplicate issue, I think it is the same. After using this plugin, for anywhere between 5-45 minutes OBS completely locks up. It happens very frequently. It makes this plugin unuseable. The stream continues, but the scenes do not switch and I can not interact with the OBS window. I am not sure what information to give other than when it happened on stream at 40:45 https://www.twitch.tv/videos/589428140?t=0h40m45s

I am using a fresh install of OBS and Advanced Scene Switcher, the only thing I have set up is to switch the stream based on what monitor my cursor is on. https://imgur.com/SojrGX3 All other settings are default. Is there something I am doing wrong? Or is a modern update to OBS causing this plugin to break? I am using obs 25.0.4. As of writing the latest version of the software.

Thanks!

qaptoR commented 4 years ago

Hello, I am also having the same issue as @slidedrum, I believe I've narrowed down the issue as being due to a high number of scene switches. I have the switcher set to change display capture scenes for two monitors based on mouse location, and I can cause OBS to freeze by simply forcing constant scene changes one after the other between these two monitors.

I am also using 25.0.4. My system is fully updated as well.

UPDATE: Efforts to reproduce issue seem to reveal that high velocity scene switching causes a freeze. over 200 slow rhythmic switches proved that volume is not the determining factor. Trying to cause another switch before the previous transition finishes may be part of the problem...

UPDATE: Efforts to reproduce issue after changing scene transitions to "cut" fail, i.e. the issue seems to lie in the timing of the switches as the scene transitions fade.

UPDATE: Setting ONE monitor region scene switch to "fade" proved that fading is an issue. Eventually, after rapid velocity changes the scene refuses to switch to monitor with fade transition until a manual switch to new scene, which seems to "reset" the transition queue? (if that's a thing). follow up rapid succession switches cause the scene to fail to switch eventually. However, it should be noted that OBS does not freeze.

SUMMARY: A temporary fix is to make all scene transitions "cut", that way there is no queue buildup that leads to a freeze.

Thank you

slidedrum commented 4 years ago

SUMMARY: A temporary fix is to make all scene transitions "cut", that way there is no queue buildup that leads to a freeze.

Thank you

Thanks! I will try that as a workaround for now. Fade looks nicer, but if it stops OBS from freezing, I can definitely live with a cut transition.

Have you checked if "Check switch conditions every Xms" makes an impact? I feel like that may change something.

qaptoR commented 4 years ago

Have you checked if "Check switch conditions every Xms" makes an impact? I feel like that may change something.

I did not know that was a setting. I will test that.

WARNING: Setting transition back to "cut" from "fade" after causing single monitor to stop transition causes the ENTIRE computer to freeze and require a reboot. This is either because I did not manually "reset" the switching queue with a manual transition, OR because I did not restart OBS after two successive attempts to freeze the program.

qaptoR commented 4 years ago

Have you checked if "Check switch conditions every Xms" makes an impact? I feel like that may change something.

UPDATE: Changing this setting to 750ms proves successful. Unable to reproduce freeze issue with rapid succession scene switches.

UPDATE: Narrowed window to 320ms and still unable to reproduce freeze. However 315ms does! Hence, ~20ms must be a sensible window to add onto the length the longest scene transition (as default fade is 300ms). Keep in mind that all systems are different and Your mileage may vary significantly.

Cheers!

WarmUpTill commented 4 years ago

Hi @slidedrum and @q1pt2rx, thank very much for the detailed description of the reproduction scenario!

Because of this I think I was able to track the issue down and understand it: The callback handler of the scene switcher for the event "OBS_FRONTEND_EVENT_SCENE_CHANGED" tries to acquire a lock which is currently being held by the main loop of the scene switcher, which itself tries to change the current scene using the "obs_frontend_set_current_scene" function. This function call however seems to be blocked itself. (I assume until all event callback are handled)

Example:

... SwitcherData::Thread(void) holding lock SwitcherData::Thread(void) holding lock SwitcherData::Thread(void) holding lock User switched to scene 'Scene 1' SwitcherData::Thread(void) holding lock OBSEvent(obs_frontend_event, void *) try acquire lock

Meanwhile the callstack of the scene switcher shows it being stuck in obs_frontend_set_current_scene:

obs64.exe!OBSStudioAPI::obs_frontend_set_current_scene(obs_source scene) Line 108 C++ obs-frontend-api.dll!obs_frontend_set_current_scene(obs_source scene) Line 113 C++ advanced-scene-switcher.dll!switchScene(OBSRef<obs_weak_source ,&obs_weak_source_addref,&obs_weak_source_release> & scene, OBSRef<obs_weak_source ,&obs_weak_source_addref,&obs_weak_source_release> & transition, std::unique_lock & lock) Line 1100 C++

To resolve the problem I added an unlock of the mutex before calling obs_frontend_set_current_scene. (I also added these unlock calls before obs_frontend_set_current_transition just in case it has a similar dependency to OBS_FRONTEND_EVENT_SCENE_CHANGED)

I attached an example build of the scene switcher for Windows 64 bit. (Assuming attaching this here works) deadlock_fix.zip

It would be great if you could try this on your end.

Unfortunately I do not known when I will get around to building and releasing this fix.

WarmUpTill commented 4 years ago

I assume this is solved