search

mpv-player / mpv

🎥 Command line video player
https://mpv.io
Other
28.55k stars 2.92k forks source link

Events Delay When Loading Many Instances From DLL #6705

Open mysteryx93 opened 5 years ago

mysteryx93 commented 5 years ago

I'm using MPV v0.29.1 on Windows 10, the DLL version via a .NET program.

I have created a usercontrol to display a MPV player in a .NET application. I will load 20 such controls at the same time to play 20 files in parallel.

Expected behavior: they should all start playing right away and each player have their state ready.

Current behavior: all files start playing right away, but the MediaLoaded event only gets fired for the first 8 files right away, then one MediaLoaded is triggered per second, so it takes 12 seconds until all controls are in a playing state. The file position however indicates that they were all playing from the start, because when the last file gets MediaLoaded, it shows the file is at 0:12.

I inserted some debug code to view how the events are triggered and it gave this.

11:29:02 AM - Idle
11:29:02 AM - PropertyChange
11:29:02 AM - StartFile
11:29:02 AM - Idle
11:29:02 AM - StartFile
11:29:02 AM - PropertyChange
11:29:02 AM - TracksChanged
11:29:02 AM - MetadataUpdate
11:29:02 AM - AudioReconfig
11:29:02 AM - FileLoaded
11:29:02 AM - TracksChanged
11:29:02 AM - Idle
11:29:02 AM - StartFile
11:29:02 AM - TracksChanged
11:29:02 AM - Idle
11:29:02 AM - MetadataUpdate
11:29:02 AM - MetadataUpdate
11:29:03 AM - PropertyChange
11:29:03 AM - AudioReconfig
11:29:03 AM - FileLoaded
11:29:03 AM - StartFile
11:29:03 AM - TracksChanged
11:29:03 AM - AudioReconfig
11:29:03 AM - MetadataUpdate
11:29:03 AM - FileLoaded
11:29:03 AM - AudioReconfig
11:29:03 AM - FileLoaded
11:29:03 AM - Idle
11:29:03 AM - StartFile
11:29:03 AM - PropertyChange
11:29:03 AM - Idle
11:29:03 AM - StartFile
11:29:03 AM - PropertyChange
11:29:03 AM - TracksChanged
11:29:03 AM - MetadataUpdate
11:29:03 AM - AudioReconfig
11:29:03 AM - FileLoaded
11:29:03 AM - Idle
11:29:03 AM - PropertyChange
11:29:03 AM - StartFile
11:29:03 AM - TracksChanged
11:29:03 AM - MetadataUpdate
11:29:03 AM - AudioReconfig
11:29:03 AM - FileLoaded
11:29:03 AM - TracksChanged
11:29:03 AM - MetadataUpdate
11:29:03 AM - AudioReconfig
11:29:03 AM - FileLoaded
11:29:03 AM - AudioReconfig
11:29:03 AM - AudioReconfig
11:29:03 AM - PlaybackRestart
11:29:03 AM - AudioReconfig
11:29:03 AM - AudioReconfig
11:29:03 AM - AudioReconfig
11:29:03 AM - AudioReconfig
11:29:03 AM - AudioReconfig
11:29:03 AM - AudioReconfig
11:29:03 AM - AudioReconfig
11:29:03 AM - AudioReconfig
11:29:03 AM - AudioReconfig
11:29:03 AM - Idle
11:29:03 AM - StartFile
11:29:03 AM - PlaybackRestart
11:29:03 AM - PropertyChange
11:29:03 AM - PlaybackRestart
11:29:03 AM - AudioReconfig
11:29:03 AM - PropertyChange
11:29:03 AM - AudioReconfig
11:29:03 AM - PlaybackRestart
11:29:03 AM - AudioReconfig
11:29:03 AM - PlaybackRestart
11:29:03 AM - PropertyChange
11:29:03 AM - TracksChanged
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PlaybackRestart
11:29:03 AM - MetadataUpdate
11:29:03 AM - PlaybackRestart
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - AudioReconfig
11:29:03 AM - FileLoaded
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - AudioReconfig
11:29:03 AM - AudioReconfig
11:29:03 AM - PlaybackRestart
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:03 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - Idle
11:29:04 AM - StartFile
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - TracksChanged
11:29:04 AM - MetadataUpdate
11:29:04 AM - AudioReconfig
11:29:04 AM - FileLoaded
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - AudioReconfig
11:29:04 AM - AudioReconfig
11:29:04 AM - PlaybackRestart
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:04 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - Idle
11:29:05 AM - StartFile
11:29:05 AM - TracksChanged
11:29:05 AM - MetadataUpdate
11:29:05 AM - AudioReconfig
11:29:05 AM - FileLoaded
11:29:05 AM - AudioReconfig
11:29:05 AM - AudioReconfig
11:29:05 AM - PlaybackRestart
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:05 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - Idle
11:29:06 AM - StartFile
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - TracksChanged
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - MetadataUpdate
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - AudioReconfig
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - FileLoaded
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - AudioReconfig
11:29:06 AM - PropertyChange
11:29:06 AM - AudioReconfig
11:29:06 AM - PlaybackRestart
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:06 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - Idle
11:29:07 AM - StartFile
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - TracksChanged
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - MetadataUpdate
11:29:07 AM - AudioReconfig
11:29:07 AM - PropertyChange
11:29:07 AM - FileLoaded
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - AudioReconfig
11:29:07 AM - AudioReconfig
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
11:29:07 AM - PropertyChange
...
ghost commented 5 years ago

Maybe the scheduler just lets the other instances starve? Did you try loading them in paused state, and then unpausing them all at once?

Closing it since there's no clear bug here, and it's an old issue (don't know if the reporter is still around).

mysteryx93 commented 5 years ago

Setting AutoPlay to false doesn't solve the problem, it still takes the same amount of time before each file initializes.

Furthermore, closing my app before all instances are loaded causes it to freeze and the process never ends.

ghost commented 5 years ago

"AutoPlay" isn't a thing in mpv and I don't know what you mean by it.

mysteryx93 commented 5 years ago

It's a feature in the API implementation I'm using; but doesn't really matter https://github.com/hudec117/Mpv.NET-lib-

By simply loading the files without playing them, the problem persists, and closing the window before all instances are loaded causes the process to hang. I debugged the .NET library; but the bug isn't in it but in MPV library itself.

I don't think we should close this issue without even investigating it.

ghost commented 5 years ago

Well, I don't think this is actionable anyway.

mysteryx93 commented 5 years ago

Probably first step would be to recreate the issue in a simple project. I probably can do that when I have time. For debugging the MPV library, however, it would be better if a MPV dev can look into it.

mysteryx93 commented 5 years ago

Here is a simple reproduction of the issue. Set the path of a valid audio file in CustomPlayer.xaml.cs, and set the number of instances in MainWindow.xaml.cs

Lights should all turn green when starting. It you set 20 instances and start, 10 go green, then 1 per second. That's the first bug.

Second bug is that if you close the window before all 20 instances are loaded, it freezes. However, this only happens if we call Dispose during the event Dispatcher.ShutdownStarted (since Unloaded event isn't triggered during app shutdown)

MpvLoadingBug.zip

Sample requires Visual Studio 2019, and just copy mpv-1.dll to the bin/Debug folder.

Edit: the 2nd bug happens when calling Dispose before the instance has been initialized: hell breaks loose. If it's not on app exit, then the app completely freezes.

OneB1t commented 4 years ago

There is definitely something weird when calling dispose event on not completely loaded/allready closing/seeking video but for me visual studio and application always freeze and restarts so it is hard to tell where this issue happens

image it freezes in way that im unable to click on anything :-( until it automatically restarts

When video is running it works very well there is no memory leak or anything i can leave it running for days without any side effects.

Maybe something in this part of code inside MpvEventLoop.cs image

mysteryx93 commented 4 years ago

Visual Studio freezes because the bug is in unmanaged code within the compiled library itself. Nothing Visual Studio can do about it. You'd have to debug while running the source code of MPV itself.

OneB1t commented 4 years ago

Problem is that there is no simple way to run MPV code in debug from VS right? Or can someone point me how to manage that? :-)

mysteryx93 commented 4 years ago

MPV is written in C++. Add the MPV DLL project to your project in Visual Studio, load the DLL compiled in Debug mode from your own project, and debugging should then be enabled when you run your app.

First, you'll have to figure out how to simply compile MPV locally and where that DLL project is located.

Hum... compilation seems complicated and requires special tools. I'm not sure whether you can compile straight from Visual Studio to have the debugger; or how to debug that code. https://github.com/mpv-player/mpv/blob/master/DOCS/compile-windows.md

ghost commented 4 years ago

mpv is written in C, and since MSVC support for C is borderline broken (plus mpv relying on some MinGW things), you can't use it to build mpv. mpv needs to be built with MinGW.

A few years ago it was not possible at all to build a binary with MinGW that has MSVC compatible debug infos. I don't know if this changed yet.

There's a rejected PR that made it sort-of build on MSVC, but I don't remember its number.

We should probably add more debug prints around the suspected crash site...

mysteryx93 commented 4 years ago

So how do you debug MPV code?

Well, there's this https://visualgdb.com/tutorials/mingw/

ghost commented 4 years ago

I hear sometimes mingw gdb works, but that probably won't work with .net applications.

ghost commented 4 years ago

Also...

Is the mpv API call that crashes mpv_wakeup? Can you list what API functions get called before that?