CarterLi / iina

The modern video player for macOS with additional features and bug fixes.
https://iina.io
GNU General Public License v3.0
678 stars 29 forks source link

Closing and opening files leads to Iina to crash and not respond #17

Open ViRo3 opened 2 years ago

ViRo3 commented 2 years ago

When files are opened and closed successively, Iina freezes on opening a file and then doesn't respond.

System and IINA version:

Expected behavior: Doesn't crash/freeze

Actual behavior:

Iina crashes and freezes on quickly opening and closing files.

Crash report:

Sample of IINA.txt Spindump.txt Spindump2.txt

Steps to reproduce:

Keep opening and closing a file (doesn't require much but 3 cycles for me)

How often does this happen? Always

PS : File responsible hxxps://nyaa<.>si/view/1390968

low-batt commented 2 years ago

Investigating.

low-batt commented 2 years ago

IINA v1.2.0-21 is from 6 days ago and is missing the fix for my fix from 4 days ago. This report got me to look at the fix again and I've just pushed another commit that tweaks it some more to hopefully make really sure the hang is fixed.

@CarterLi Please create a new build when you get a chance.

CarterLi commented 2 years ago

IINA v1.2.0-21 is from 6 days ago and is missing the fix for my fix from 4 days ago. This report got me to look at the fix again and I've just pushed another commit that tweaks it some more to hopefully make really sure the hang is fixed.

@CarterLi Please create a new build when you get a chance.

Done

I'd like to use Github Actions building M1 versions when supported. Ref: https://github.com/actions/virtual-environments/issues/2187

ViRo3 commented 2 years ago

Sample of IINA.txt

Spindump.txt @low-batt still crashes with the file linked above (would rec downloading it if possible)

low-batt commented 2 years ago

@ViRo3, @CarterLi New plan. Stablize IINA-Plus:

I've just pushed a commit that backs out the changes made to fix iina#3601. Need a new build.

The issue iina#3601 is about wasting a minor amount of energy. Desirable to eventually fix, but not critical to fix it right now with the "fix" causing so much trouble. Unfortunately the timing on my Mac is such that so far I've not been able to reproduce these hangs. So I've been taking a "stab in the dark" as to what is going wrong and how to fix it. Clearly that is not working. More important to focus on other issues. I alway hate to give up on fixing an issue but that seems like the right decision on this one for now.

I did leave in one change made as a part of this fix which was to add guarding that videoPosition is available in PlaybackInfo.constrainVideoPosition:

guard let duration = videoDuration, let position = videoPosition else { return }

That seems like a safe useful change. The change that was triggering the problem is the attempt to stop and start the timer that synchronizes the OSC based on whether the OSC is visible or not. Backing out the change puts IINA back to updating the OSC even though it is not visible to the user. This wastes some energy, but the vast majority of CPU time consumed is in the code that displays the video.

low-batt commented 2 years ago

By the way, there is an IINA hang out there lurking, the issue "Main thread hang in mpv_render_context_create during startup". So if IINA hangs during startup don't assume it was one of these recent issues. Always need a sample of IINA to have a chance of knowing what the issue is. I hit that hang once with the released version of IINA. I also hit it once with a development version of IINA using mpv 0.34.0. I made a concerted effort to reproduce it, running a test designed to trigger it thousands of times. No luck. Whatever that problem is, it is rare.

ViRo3 commented 2 years ago

Yes, its a very specific file that completely freezes Iina. (Have link it above) so as such it isn't really a major issue

CarterLi commented 2 years ago

New binary released. Please test it

ViRo3 commented 2 years ago

Sample of IINA.txt Spindump.txt

CarterLi commented 2 years ago

So It's not caused by fixing iina#3601.

Please test this version: https://github.com/iina-plus/iina/releases/tag/v1.2.0-25

low-batt commented 2 years ago

I'm currently tired and may not be thinking straight...

From a quick look I am stunned and confused. The process sample shows the same main thread lockup with mpv_get_property waiting for a lock when called by PlayerCore.syncUI. I was expecting that was somehow due to my "fix" that changed how that method was used. I quickly checked MainWindowController on GitHub and it looked like I correctly backed out that fix.

This movie plays fine with the released verion of IINA? The hang only occurs with IINA Plus?

There is one other change in IINA Plus that has to do with PlayerCore.syncUI. The timer that runs this method to keep the UI in sync is now paused and restarted as you pause and restart the video. IINA Plus also has the changes related to the OpenGL context. I was not thinking this was related to that change as it is obvious in the spin dump when a thread is stuck waiting to lock the context. Of course the big change is that IINA Plus is using the latest mpv release, 0.34.1.

When exactly is this hang triggered? When it hangs what is the video doing? Just freezes?

I will be taking a closer at the other threads in the spin dump to see if I can spot something that looks wrong. Might have to pull some of these other fixes and see what effect that has on the problem. I guess we first see if the new build makes any sort of difference.

CarterLi commented 2 years ago

I encountered freezing after using DispatchQueue.main.async once and I did add a DispatchQueue.main.async block recently.

I just removed it. Let's see what's happening next

low-batt commented 2 years ago

@ViRo3 Are you able to play the video using mpv without problems?

I'm thinking we should take a look at the IINA and mpv log files. Usually log files don't help that much with hangs. But if there is trouble with playback we might find some clues in the mpv log.

The sample shows the main thread completely locked up:

    +                             2257 __NSFireTimer  (in Foundation) + 104  [0x18a23e29c]
    +                               2257 @objc PlayerCore.syncUITime()  (in IINA) + 28  [0x1004595d4]
    +                                 2257 PlayerCore.syncUITime()  (in IINA) + 56  [0x1004594e4]
    +                                   2257 PlayerCore.syncUI(_:)  (in IINA) + 584  [0x10045982c]
    +                                     2257 mpv_get_property  (in libmpv.1.dylib) + 92  [0x103664bec]
    +                                       2257 mp_dispatch_lock  (in libmpv.1.dylib) + 188  [0x1036433cc]
    +                                         2257 _pthread_cond_wait  (in libsystem_pthread.dylib) + 1228  [0x18925d808]
    +                                           2257 __psynch_cvwait  (in libsystem_kernel.dylib) + 8  [0x1892250c0]

As I had just added a change involving PlayerCore.syncUI I assumed that was triggering the problem. Since backing that out didn't work I've been digging into mpv code.

This is the mpv method that is being called by IINA code:

int mpv_get_property(mpv_handle *ctx, const char *name, mpv_format format,
                     void *data)
{
    if (!ctx->mpctx->initialized)
        return MPV_ERROR_UNINITIALIZED;
    if (!data)
        return MPV_ERROR_INVALID_PARAMETER;
    if (!get_mp_type_get(format))
        return MPV_ERROR_PROPERTY_FORMAT;

    struct getproperty_request req = {
        .mpctx = ctx->mpctx,
        .name = name,
        .format = format,
        .data = data,
    };
    run_locked(ctx, getproperty_fn, &req);
    return req.status;
}

That method is stopped calling run_locked:

// Run a command in the playback thread.
static void run_locked(mpv_handle *ctx, void (*fn)(void *fn_data), void *fn_data)
{
    mp_dispatch_lock(ctx->mpctx->dispatch);
    fn(fn_data);
    mp_dispatch_unlock(ctx->mpctx->dispatch);
}

That method is stopped calling mp_dispatch_lock:

// Grant exclusive access to the target thread's state. While this is active,
// no other thread can return from mp_dispatch_lock() (i.e. it behaves like
// a pthread mutex), and no other thread can get dispatch items completed.
// Other threads can still queue asynchronous dispatch items without waiting,
// and the mutex behavior applies to this function and dispatch callbacks only.
// The lock is non-recursive, and dispatch callback functions can be thought of
// already holding the dispatch lock.
void mp_dispatch_lock(struct mp_dispatch_queue *queue)
{
    pthread_mutex_lock(&queue->lock);

So the main thread is blocked trying to run a get property request on the playback thread. Maybe this particular video is causing trouble for the playback thread.

low-batt commented 2 years ago

@CarterLi I submitted a PR for IINA that has a simple workaround for iina#3211. Was not sure if we are currently holding off adding changes to IINA+ until we sort this issue? Or do you want me to add that fix?

By the way Daniel on Telegram said nice things about IINA+ HDR support.

@ViRo3 I've been hoping you would have time to see if you can reproduce the same problem in the mpv player. If mpv plays it without issues we focus more on how we are configuring mpv and interacting with it. If mpv has trouble that would explain our trouble trying to track down the problem.

CarterLi commented 2 years ago

@CarterLi I submitted a PR for IINA that has a simple workaround for iina#3211. Was not sure if we are currently holding off adding changes to IINA+ until we sort this issue? Or do you want me to add that fix?

Like I said before, this repo is built for experimenting latest features / bug fixes that may not be very stable. You may just push your changes. We can revert the change if it causes serious issues.

low-batt commented 2 years ago

I was nervous due to the issues with my previous fix. This fix is small and should be safe. Just finished pushing it.

CarterLi commented 2 years ago

I was nervous due to the issues with my previous fix. This fix is small and should be safe. Just finished pushing it.

I'm very sorry that I removed your commit with a force-push by accident. Can you push it again?

low-batt commented 2 years ago

Not a problem at all. I've pushed the fix to VideoView again.

CarterLi commented 2 years ago

Can you build iina-plus yourself now? You may make a new release if necessary @low-batt

low-batt commented 2 years ago

It is painful for me to build the dependencies part as I operate under a limited account that does not have the access needed for brew, so I have to build that part under an admin account. I just tried and the build worked up to the very end which failed because it could not find create-dmg. I see some shell scripts with that name on GitHub. Where did you get it?

CarterLi commented 2 years ago

https://github.com/Homebrew/homebrew-core/blob/master/Formula/create-dmg.rb

brew install create-dmg

John-He-928 commented 2 years ago

The problem is still reproducible right now.

Tested on version 1.2.0-22, 1.2.0-28 and 1.2.0-29. It's okay on IINA 1.2.0.

low-batt commented 2 years ago

Unfortunately freezes can be very senstive to the specific timing of hardware and configuration and the like. So far I've not been able to reproduce this hang which makes it much harder to debug.

There is a ton of differences between IINA 1.2.0 and IINA+ builds. One major difference is that IINA+ uses the latest mpv. There are some known hangs in mpv. We are hoping someone can test and see if mpv is working fine on the same files or not just to confirm that it is something IINA is doing rather than something in the new mpv.

Hangs are hard to debug. With a hang we always need a process sample. To take a process sample bring up the Activity Monitor while IINA is frozen. Select IINA in the Activity Monitor. Then under the View menu select Sample Process. That should create a report like you see above. From that we should be able to tell if you are hitting the same freeze or not. It might or might not provide an additional clue to the problem.

John-He-928 commented 2 years ago

I made more tests. It seems to be 100% reproducible for my environment, which is MBP M1 Pro.

Testing clip is LG Earth Dolby Vision Demo, but it actually freezes on many of my clips, if not all.

I tested mpv 0.34.1 prebuilt from here. It successfully quits without hangs or freezes. It's an x86_64 build. Sorry but I'm not able to find an arm64 binary distribution.

I made a process sample and pasted the text to this gist.

iina.log mpv.log

Config file used:

profile=gpu-hq
icc-profile-auto=yes
gamma-auto=yes
sub-auto=fuzzy
sub-codepage=utf8:gb18030
osd-font='PingFangSC-Light'
sub-font='PingFangSC-Light'
autofit-larger=90%x80%
hwdec=auto

Disable loading mpv config file doesn't help.

low-batt commented 2 years ago

@John-He-928 Thank you so much for running these tests. Very helpful.

From the process sample this looks like my bad, not a mpv issue. It does not look like the same problem in the samples provided by ViRo3.

I'm trying to fix a crash that sometimes happens when you quit IINA. The problem occurs because IINA was telling mpv to quit, but not waiting for it to finish shutting down. Depending upon the timing of things that can cause IINA to crash out. When I changed IINA to wait for mpv that brought out some other shutdown problems.

This seems like something has gone wrong with waiting for mpv to finish. I just looked at this, so I'm going to have to think on what could be going wrong.

I've tried to obtain files from 4kmedia.org before. I'm seeing the same error I've seen in the past. Google Drive says:

Sorry, you can't view or download this file at this time.

Too many users have viewed or downloaded this file recently. Please try accessing the file again later. If the file you are trying to access is particularly large or is shared with many people, it may take up to 24 hours to be able to view or download the file. If you still can't access a file after 24 hours, contact your domain administrator.

I should be able to figure out this one without the video file. Stay tuned.

low-batt commented 2 years ago

The code in AppDelegate used to look like this:

  func applicationShouldTerminate(_ sender: NSApplication) -> NSApplication.TerminateReply {
    Logger.log("App should terminate")
    for pc in PlayerCore.playerCores {
     pc.terminateMPV()
    }
    return .terminateNow
  }

What was wrong with that is that terminateMPV did not actually terminate mpv. It started mpv terminating asynchronously in the background. This creates a race condition between background threads and the main thread. This would sometimes result in crashes.

That method now looks like:

  func applicationShouldTerminate(_ sender: NSApplication) -> NSApplication.TerminateReply {
    Logger.log("App should terminate")
    for pc in PlayerCore.playerCores {
     pc.terminateMPV()
    }
    // The call to terminateMPV instructed mpv to quit, but that is happening asynchronously in the
    // background. Must wait for mpv to finish terminating before allowing Cocoa to terminate the
    // application. This must be done in another thread to avoid blocking the main thread.
    terminateQueue.async {
      // Normally mpv will quickly terminate, but we will impose a time limit to insure termination
      // of the application is not blocked.
      Logger.log("Waiting for mpv termination")
      let timeout = DispatchTime.now() + DispatchTimeInterval.milliseconds(500)
      for pc in PlayerCore.playerCores {
        let result = pc.waitForTermination(timeout: timeout)
        if result == .timedOut {
          Logger.log("Timeout waiting for termination of player core", level: .warning)
        }
      }
      // Tell Cocoa to proceed with termination. This has to be done on the main thread.
      DispatchQueue.main.async {
        Logger.log("Proceeding with termination")
        NSApp.reply(toApplicationShouldTerminate: true)
      }
    }
    // Tell Cocoa that it is ok to proceed with termination, but wait for our reply.
    return .terminateLater
  }

It now submits a background task that waits for mpv to finish terminating. When that is done it submits a main thread task to inform the framework it can continue with termination.

The Apple documentation for the method applicationShouldTerminate discusses using terminateLater and then invoking reply(toApplicationShouldTerminate:) when the application is ready to terminate.

The IINA log shows the timeout kicked in while waiting for mpv to terminate and is missing the "Proceeding with termination" message:

03:15:45.197 [thumbcache][d] Finished reading thumbnail cache, 69 in total
03:15:45.274 [player0][d] Track list changed
03:15:47.075 [iina][d] App should terminate
03:15:47.076 [player0][d] Write watch later config
03:15:47.089 [iina][d] Waiting for mpv termination
03:15:47.594 [iina][w] Timeout waiting for termination of player core

Not sure why the mpv log has two entries mentioning running the quit command. That is unexpected. Maybe related to why termination timed out?:

[   6.796][d][cplayer] Run command: quit, flags=73, args=[code="0"]
[   6.797][d][global] config path: '/Users/user/Library/Application Support/com.colliderli.iina/watch_later' -> '/Users/user/Library/Application Support/com.colliderli.iina/watch_later'
[   6.797][i][cplayer] Saving state.
[   6.798][v][cplayer] EOF code: 5  
[   6.823][d][ad] Uninit decoder.
[   6.823][d][vd] Uninit decoder.
[   6.838][d][cplayer] Terminating demuxers...
[   6.841][d][cplayer] Done terminating demuxers.
[   6.841][v][cplayer] finished playback, success (reason 3)
[   6.841][i][cplayer] 
[   6.841][d][ytdl_hook] Exiting...
[   6.841][d][console] Exiting...
[   6.841][d][stats] Exiting...
[   6.842][d][cplayer] Run command: write-watch-later-config, flags=64, args=[]
[   6.854][d][libmpv_render] flushing shader cache
[   6.855][d][cplayer] Run command: quit, flags=64, args=[code="0"]

The process sample shows the main thread just waiting around:

    + 2515 -[NSApplication terminate:]  (in AppKit) + 756  [0x1ab8027d8]
    +   2515 -[NSApplication _shouldTerminate]  (in AppKit) + 1024  [0x1ab81206c]
    +     2515 -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:]  (in AppKit) + 1332  [0x1ab57b584]
    +       2515 _DPSNextEvent  (in AppKit) + 844  [0x1ab57cce0]
    +         2515 _BlockUntilNextEventMatchingListInModeWithFilter  (in HIToolbox) + 72  [0x1b15b8a9c]
    +           2515 ReceiveNextEventCommon  (in HIToolbox) + 552  [0x1b15b8cdc]
    +             2515 RunCurrentEventLoopInMode  (in HIToolbox) + 292  [0x1b15b8f68]
    +               2515 CFRunLoopRunSpecific  (in CoreFoundation) + 600  [0x1a8a26734]
    +                 2515 __CFRunLoopRun  (in CoreFoundation) + 1212  [0x1a8a27390]
    +                   2515 __CFRunLoopServiceMachPort  (in CoreFoundation) + 372  [0x1a8a28ed8]
    +                     2515 mach_msg  (in libsystem_kernel.dylib) + 76  [0x1a8921d00]
    +                       2515 mach_msg_trap  (in libsystem_kernel.dylib) + 8  [0x1a8921954]

It is as if IINA failed to tell Cocoa to proceed with termination.

I looked around the Internet for examples of delaying termination. I found some that followed the same pattern in the above code.

The only thing I don't like in the new code is that the array PlayerCore.playerCores is being accessed by the background thread. I don't think it is being modified, but the background thread probably should be operating on its own copy to be certain no other thread is messing with the array. I have made that change and added some log messages for debugging.

I'm a bit stumped by this one. Once we have a new build lets see if the debug messages tell us anything.

CarterLi commented 2 years ago

New build released

ViRo3 commented 2 years ago

@low-batt I tried the file with mpv; doesn't freeze.I have also provided link to the file above for replicating crash/freeze. (Iina just cannot run it) Attached additional logs Sample of IINA.txt Spindump.txt Spindump2.txt

low-batt commented 2 years ago

@ViRo3 Thanks for checking mpv. Very helpful to know it does not reproduce with mpv. There are other changes we can pull out to see if that changes the behavior. Tuesday is the day of the week that I'm really busy so might not get to that today. I have not tried out the file you posted a link to as that is the kind of site my ISP is unhappy with customers visiting.

The hang @John-He-928 has reported is a completely different issue. As of this morning I have a new working theory on that one. Need to dig into the code and see if that theory pans out.

While trying to reproduce these problems I instead managed to reproduce a 3rd hang. This one looks to be a mpv problem in their logger. I hit it when I raised the mpv logging level. I still need to see if I can reproduce it directly in mpv. This seems like the problem I mentioned a while back regarding mpv_render_context_create. I've gotten as far as finding that mpv did make some changes in 2020 related to locking in their logger.

Thank you both for helping with debugging these issues. It is very much appreciated.

John-He-928 commented 2 years ago

@low-batt Thank you for the fix, but no luck, it seems not fixing the problem. IINA is freezing when exit. Tested on version 1.2.0-30

IINA sample.txt iina.log mpv.log

low-batt commented 2 years ago

I did not have confidence that fix would work. I have just pushed another fix. I still haven't been able to reproduce the problem, but in a test earlier today I changed the code to force it to malfunction the way that it would if what I suspect could be happening was happening. That caused two of the symptoms we are seeing. This message in the log:

Timeout waiting for termination of player core

And the application hanging in the same place.

That is encouraging, but the log files didn't entirely match up. So I'm very unsure about this fix as well.

The latest mpv log file shows the quit command being run over and over again. The debug log messages I added indicate IINA only sent that command once. That is confusing and alarming.

I added a couple more log messages for debugging. That may let us rule out some theories on what is happening.

ViRo3 commented 2 years ago

@low-batt here's more logs if it helps diagnose the issue iina.txt mpv.txt

low-batt commented 2 years ago

Thanks! I am currently looking into something I'm worried about with the startup hang. Stay tuned.

ottob commented 2 years ago

https://github.com/iina-plus/iina/actions/runs/1749900561 locks up all the time for me if I try to quit using the q keyboard shortcut instead of cmd-q. This does not happen with the official 1.2.0 version.

low-batt commented 2 years ago

@ottob Thanks so much for reporting that. I had not been able to reproduce the shutdown hang, but quitting using q locked up for me. This gives me the ability to dig into what is going wrong without pestering people for debugging information.

As for why the official 1.2.0 works. It doesn't. It sometimes crashes. I'm trying to fix that, but somehow my fix created a much worse situation. With it failing for me I am able to debug the problem. Stay tuned.

low-batt commented 2 years ago

@John-He-928 @ottob I now know what is going wrong. When testing my original fix I did not know how to trigger one of the code paths. That is the code path pressing q triggers and sure enough that path is not working right. Will be working on a fix today.

@ViRo3 In IINA preferences under Video/Audio there is a preference "Hardware decoder" which should be set to "Auto". Set that to "Disabled", restart IINA and try playing the problematic video. If that reproduces the problem please post a process sample and logs. Don't forget to set that back to "Auto". Still trying to figure out this one...

ViRo3 commented 2 years ago

It works when hardware decoding is disabled!

low-batt commented 2 years ago

Isn't that interesting. That is suggestive of a problem with the hardware drivers, but with this kind of problem it is good to keep digging at it before leaping to a conclusion. This brings up the question of why did mpv work. Did mpv default to software decoding? Might need to test mpv again with different options. I will investigate that. There were a couple of concerning messages in the mpv log. There are a whole bunch of these messages:

[   0.373][d][mkv] Ignoring unrecognized subelement. ID: 447b size: 2
[   0.373][d][mkv] Ignoring unrecognized subelement. ID: 447b size: 2

As those are debug messages, hopefully they are not significant. But these are warnings. Looks like FFmpeg is not happy:

[   0.374][w][ffmpeg/video] hevc: Unknown HEVC profile: 0
[   0.374][w][ffmpeg/video] hevc: Unknown HEVC profile: 0

This from the log is particularly interesting:

[   0.374][v][ad] Codec list:
[   0.374][v][ad]     flac - FLAC (Free Lossless Audio Codec)
[   0.374][v][ad] Opening decoder flac
[   0.374][v][ad] Detected 8 logical cores.
[   0.374][v][ad] Requesting 9 threads for decoding.
[   0.374][v][ad] Selected codec: flac (FLAC (Free Lossless Audio Codec))

Because there is this open mpv issue reporting a hang with FLAC encoded files: https://github.com/mpv-player/mpv/issues/9385

Too soon to say if it is that issue we are encountering. I will thinking on next steps. But at the moment I need to focus on the hang during quit as it is proving hard to fix.

low-batt commented 2 years ago

@John-He-928 @ottob I have just published v1.2.0-32 with a fix (fingers crossed) for the hang while quitting.

@ViRo3 I'll turn my attention to mpv now and look into the theory that the hang that started this issue is related to that mpv problem with FLAC.

I'll also be looking into the hang that seems to be a problem in the mpv logger.

John-He-928 commented 2 years ago

@low-batt I checked 1.2.0-32 and the problem was fixed. Amazing!

ottob commented 2 years ago

Yes, it works for me too. Thanks!

low-batt commented 2 years ago

@John-He-928 @ottob Relieved to hear the fix worked for you. @ViRo3 Been looking into the hang first reported in this issue. More on that in a second.

To all three of you, thank you so much for your patience and help in debugging these issues. You all have been of tremendous help.

I don't know whether you have some programming experience and can understand what I've been posting or if some of my posts just read like programmer gibberish to you. If you would like a big picture view of what these problematic changes are all about I'd be happy to provide a user oriented explanation. Just ask.

Ok, back to work on the first hang reported by ViRo3. Previously we have identified a key piece of evidence, namely that IINA works if hardware decoding is disabled. We also previously have identified a mpv issue involving hanging when playing FLAC encoded videos and the problematic video is FLAC encoded. I looked into that mpv issue and it doesn't look to be exactly what is being seen here. Still interesting as it involves hanging and FLAC.

IINA is always asks if a problem reproduces with mpv because if it does then it is considered an "upstream" problem and has to be fixed by the mpv project. I suspect the mpv project has the same viewpoint about hardware decoding due to all the problems they have had to deal with in video drivers from hardware manufacturers.

I had you test mpv and it worked, but we were unsure if mpv used hardware decoding or not. That was one of the things I checked today and as you can see in the clip below from the mpv manual, by default mpv uses software decoding.

I would like you to repeat the test with mpv and enabling hardware decoding using the "--hwdec=auto" option as seen here:

low-batt@gag ~$ /Applications/mpv.app/Contents/MacOS/mpv --log-file=mpv.log --hwdec=auto ~/Movies/earth.mp4 

If that fails then we can say for sure that the issue is "upstream" and needs to be reported to mpv. It may prove to be "upstream" for them as well. If it works then it would be interesting to see the log.

From the mpv manual:

--hwdec=\<api> Specify the hardware video decoding API that should be used if possible. Whether hardware decoding is actually done depends on the video codec. If hardware decoding is not possible, mpv will fall back on software decoding.

Hardware decoding is not enabled by default, because it is typically an additional source of errors. It is worth using only if your CPU is too slow to decode a specific video. ... \<api> can be one of the following: no: always use software decoding (default) auto: forcibly enable any hw decoder found (see below) ... In general, it's very strongly advised to avoid hardware decoding unless absolutely necessary, i.e. if your CPU is insufficient to decode the file in questions. If you run into any weird decoding issues, frame glitches or discoloration, and you have --hwdec turned on, the first thing you should try is disabling it.

ViRo3 commented 2 years ago

mpv.txt Sample of mpv.txt Spindump.txt Okay hardware decoding do be broken! And yes, insights do help and make sense in some sort of sense so I do appreciate it! Thanks! (I haven't filed this in mpv so feel free to do so)

low-batt commented 2 years ago

With the results of that test I think we can conclude this hang is not the fault of IINA. Likely not the fault of mpv either. Are you running the macOS 12.3 Beta? Could be Apple broke something trying to improve the hardware drivers.

low-batt commented 2 years ago

@John-He-928 @ottob @ViRo3 The following is my attempt to give you some insight into the big picture of what you have been helping with without too much programmer speak. Nothing here you need to read. This is post is just in case you are curious about software development. Here is an analogy of what has been going on with IINA+:

Imagine a tiny town with no stop signs or traffic lights. For years drivers have driven right through intersections without looking for other cars. There have never been any accidents. Then one day there is a horrible collision in an intersection. The mayor asks how this could have happened. The police chief reports that it used to be only two residents owned cars, but recently 8 more residents bought cars. The mayor recognizes they had better add traffic controls, so the order goes out for stop signs to be installed.

The next day there is a collision. The mayor is shocked and asks the police chief what happened. The police chief reports a car stopped for one of the new stop signs and the car behind drove right into the stopped car. Not all drivers had gotten the message about stop signs being installed. The mayor orders public service announcements so all drivers know about the new stop signs.

The next day there is a collision. The mayor is shocked and confused and asks the police chief how that could possibly have happened now that proper traffic controls are in place and all drivers know about them. The police chief reports that again a car rear ended another car that had stopped at one of the new stop signs. The driver that failed to stop had been driving around for years without any problems even though the brakes on the car were failing. The addition of the stop signs turned the poorly functioning brakes into a serious problem. The mayor now has to order that all cars undergo inspections.

How this analogy relates to computing has to do with how computer applications perform multiple tasks at once. To do this they assign an individual task to a Thread. Usually threads need to communicate with each other. For example one thread might write a list that the other thread needs to read. Tying this back to the analogy, threads are the cars and the data they share are the intersections. A collision occurs when one thread tries to read that list at the same moment another thread is writing to that list. In programming there are various kinds of "traffic controls" that must be used to prevent such thread conflicts. As in the analogy an application can have such programming errors and work fine, with only an occasional "glitch" when the timing is just right and the threads collide. What happens when threads collide is usually considered "undefined". Maybe works. Maybe malfunctions. Maybe corrupts memory. Maybe crashes. It is the responsibility of the programmer to properly coordinate thread interaction and insure this can't possibly happen.

To understand how threads run we need to tweak the analogy a little. Imagine the town always had a lot of cars, but none of the cars had engines. One person owned all the engines and would rent them to a driver for a short time. That person used to only own two engines, so only two cars were ever actually moving at once. That person has now has 10 engines, 8 of them high performance V8s and two fuel saving inline 4s. More cars moving at once has increased the chances of collisions if proper traffic controls are not in place.

The "engines" in a computer are the CPU cores and it is macOS that "rents" a core to a thread to allow it to run. How many threads are actually running at the same time depends up the capabilities of the hardware and how macOS decides to make use the hardware. It is my own contention that with the advent of the M1 and M1 Pro / M1 Max processors more users will have Macs that can run many threads at once, potentially making festering defects related to thread coordination more likely to trigger problems. Software engineers should always have a zero tolerance for such problems. With the rollout of these processors it has become critical to fix such defects.

Since such thread related defects are dependent upon specific hardware characteristics and timing of the running of threads, they can manifest as rare "glitches". Users may not even report them if they rarely experience problems and can't reproduce the problem. This behavior also causes trouble for software engineers. Programmers would prefer to be able to deterministically reproduce a problem so that they can confirm a proposed fix works.

Reviewing code and issues shows that IINA has some problems with thread coordination that need to be fixed. The issue behind the problem reported in IINA+ issue 11 is the root cause of 7 IINA issues. I was never able to reproduce those crashes. I had to figure out the problem from the crash reports and reading code. There are other threading issues that I have been able to reproduce and fix.

So now you know who the mayor is in the analogy. I am the one that has been trying to fix these issues and triggering additional trouble with my fixes. Sorry about that! I am still digging through the code for such problems. There may be some more that need to be fixed.

There is something else you should have noticed from this post. YOU have been doing software development. The things we have been doing together to gather evidence, test out configuration changes, etc. is how developers investigate and get to the root of a non-trivial problem. You have been contributing to IINA. Thank you yet again for your efforts.

Fingers crossed further fixes won't cause such problems. But this is software, so no promises. There are other hangs lurking. I definitely suspect a hang in the mpv logger. I will be trying to reproduce that and get to the bottom of it.

I could say a lot more, but this post is already too long too read.

ViRo3 commented 2 years ago

Not possible as the beta just dropped this week and this issue persisted way back into 12.2 stable and 12.1. And yes, it seems to be a mpv macOS issue (not linux either)

low-batt commented 2 years ago

I was asking about 12.3 because this is the start of "Spindump.txt":

Date/Time:        2022-01-29 11:10:37.147 +0530
End time:         2022-01-29 11:10:47.150 +0530
OS Version:       macOS 12.3 (Build 21E5196i)
Architecture:     arm64e
low-batt commented 2 years ago

Oh. I didn't understand. You ment this can't be a recent regression added by Apple.

ViRo3 commented 2 years ago

Yes. I just updated to the beta 😅 Issue is valid in the stable release.

low-batt commented 2 years ago

Understood. As you can see from that mpv manual clip the mpv project has encountered a lot of problems with hardware drivers and takes a dim view of them. We seemed to have stumbled across one of the many issues.