iina ThreadSanitizer: data race in VideoTime.second.getter

System and IINA version:

macOS 10.15.7
IINA 1.3.0 debug build

Expected behavior: IINA runs without error when built with the thread sanitizer enabled.

Actual behavior: A debug version of IINA was built under Xcode 13.4 on a M1 MacBookPro18,2 with the thread sanitizer enabled. The resulting application was taken to a 2019 MacBookAir8,2 with an Intel chip running macOS 10.15.7. The thread sanitizer reported multiple data races and when IINA was quit the thread sanitizer triggered a crash. Will report separate issues for the different problems to isolate fixes. This issue is about this warning from the thread sanitizer:

SUMMARY: ThreadSanitizer: data race (IINA:x86_64+0x10015a2ba) in VideoTime.second.getter+0x3a

Multiple threads are accessing this PlaybackInfo property:

var videoDuration: VideoTime?

The queue "com.colliderli.iina.controller" processes mpv events and calls PlayerCore.fileLoaded which directly gets videoDuration:

    // add to history
    if let url = info.currentURL {
      let duration = info.videoDuration ?? .zero
      HistoryController.shared.add(url, duration: duration.second)
      if Preference.bool(for: .recordRecentFiles) && Preference.bool(for: .trackAllFilesInRecentOpenMenu) {
        NSDocumentController.shared.noteNewRecentDocumentURL(url)
      }
    }

And the timer running on the main thread that calls PlayerCore.syncUITime which sets videoDuration:

    case .time:
      info.videoPosition?.second = mpv.getDouble(MPVProperty.timePos)
      if info.isNetworkResource {
        info.videoDuration?.second = mpv.getDouble(MPVProperty.duration)
      }

Crash report:

Process:               IINA [29731]
Path:                  /Users/USER/Documents/*/IINA.app/Contents/MacOS/IINA
Identifier:            com.colliderli.iina
Version:               1.3.0 (131)
Code Type:             X86-64 (Native)
Parent Process:        ??? [1]
Responsible:           IINA [29731]
User ID:               502

Date/Time:             2022-06-13 16:23:53.302 -0400
OS Version:            Mac OS X 10.15.7 (19H1824)
Report Version:        12
Bridge OS Version:     6.4 (19P4242)
Anonymous UUID:        954A8385-28AB-9AF4-B895-3C24A2049280

Sleep/Wake UUID:       A633279D-633B-4221-B425-065C8C33019F

Time Awake Since Boot: 89000 seconds
Time Since Wake:       1600 seconds

System Integrity Protection: enabled

Crashed Thread:        0  Dispatch queue: com.apple.main-thread

Exception Type:        EXC_CRASH (SIGABRT)
Exception Codes:       0x0000000000000000, 0x0000000000000000
Exception Note:        EXC_CORPSE_NOTIFY

Application Specific Information:
==================
WARNING: ThreadSanitizer: data race (pid=29731)
  Write of size 1 at 0x7b10000f22b8 by main thread:
    #0 ViewLayer.needsMPVRender.setter <null>:2 (IINA:x86_64+0x1004bd54a)
    #1 ViewLayer.draw(forced:) <null>:2 (IINA:x86_64+0x1004c20fc)
    #2 MainWindowController.windowWillOpen() <null>:2 (IINA:x86_64+0x10023ab40)
    #3 PlayerCore.openMainWindow(path:url:isNetwork:) <null>:2 (IINA:x86_64+0x1005a4c4b)
    #4 PlayerCore.open(_:shouldAutoLoad:) <null>:2 (IINA:x86_64+0x1005a1894)
    #5 PlayerCore.openURLs(_:shouldAutoLoad:) <null>:2 (IINA:x86_64+0x1005a2480)
    #6 PlayerCore.openURL(_:shouldAutoLoad:) <null>:2 (IINA:x86_64+0x1005a2d25)
    #7 OpenURLWindowController.openBtnAction(_:) <null>:2 (IINA:x86_64+0x1004962d7)
    #8 @objc OpenURLWindowController.openBtnAction(_:) <null>:2 (IINA:x86_64+0x10049654f)
    #9 -[NSApplication(NSResponder) sendAction:to:from:] <null>:2 (AppKit:x86_64+0x283cf6)
    #10 start <null>:2 (libdyld.dylib:x86_64+0x1acc8)
 
  Previous write of size 1 at 0x7b10000f22b8 by thread T21 (mutexes: write M386038120195514024):
    #0 ViewLayer.needsMPVRender.setter <null>:2 (IINA:x86_64+0x1004bd54a)
    #1 ViewLayer.draw(forced:) <null>:2 (IINA:x86_64+0x1004c2be9)
    #2 closure #1 in mpvUpdateCallback(_:) <null>:2 (IINA:x86_64+0x10065af0d)
    #3 partial apply for closure #1 in mpvUpdateCallback(_:) <null>:2 (IINA:x86_64+0x1006621b9)
    #4 thunk for @escaping @callee_guaranteed () -> () <null>:2 (IINA:x86_64+0x100045752)
    #5 __tsan::invoke_and_release_block(void*) <null>:3 (libclang_rt.tsan_osx_dynamic.dylib:x86_64h+0x77f0b)
    #6 _dispatch_client_callout <null>:2 (libdispatch.dylib:x86_64+0x2657)
 
  Location is heap block of size 64 at 0x7b10000f2280 allocated by main thread:
    #0 calloc <null>:3 (libclang_rt.tsan_osx_dynamic.dylib:x86_64h+0x534a4)
    #1 _objc_rootAllocWithZone <null>:3 (libobjc.A.dylib:x86_64h+0x10804)
    #2 closure #1 in VideoView.videoLayer.getter <null>:2 (IINA:x86_64+0x1004de007)
    #3 VideoView.videoLayer.getter <null>:2 (IINA:x86_64+0x1004ddebf)
    #4 VideoView.init(frame:) <null>:2 (IINA:x86_64+0x1004e1593)
    #5 @objc VideoView.init(frame:) <null>:2 (IINA:x86_64+0x1004e1e05)
    #6 VideoView.__allocating_init(frame:player:) <null>:2 (IINA:x86_64+0x1004e1f53)
    #7 MainWindowController._videoView.getter <null>:2 (IINA:x86_64+0x1001f4251)
    #8 MainWindowController.videoView.getter <null>:2 (IINA:x86_64+0x1001f3e39)
    #9 MainWindowController.addVideoViewToWindow() <null>:2 (IINA:x86_64+0x1002258b1)
    #10 MainWindowController.windowDidLoad() <null>:2 (IINA:x86_64+0x100221307)
    #11 @objc MainWindowController.windowDidLoad() <null>:2 (IINA:x86_64+0x1002245a1)
    #12 -[NSWindowController _windowDidLoad] <null>:2 (AppKit:x86_64+0x23a72d)
    #13 PlayerCore.open(_:shouldAutoLoad:) <null>:2 (IINA:x86_64+0x1005a1894)
    #14 PlayerCore.openURLs(_:shouldAutoLoad:) <null>:2 (IINA:x86_64+0x1005a2480)
    #15 PlayerCore.openURL(_:shouldAutoLoad:) <null>:2 (IINA:x86_64+0x1005a2d25)
    #16 OpenURLWindowController.openBtnAction(_:) <null>:2 (IINA:x86_64+0x1004962d7)
    #17 @objc OpenURLWindowController.openBtnAction(_:) <null>:2 (IINA:x86_64+0x10049654f)
    #18 -[NSApplication(NSResponder) sendAction:to:from:] <null>:2 (AppKit:x86_64+0x283cf6)
    #19 start <null>:2 (libdyld.dylib:x86_64+0x1acc8)
 
  Mutex M386038120195514024 is already destroyed.
 
  Thread T21 (tid=955443, running) is a GCD worker thread
 
SUMMARY: ThreadSanitizer: data race (IINA:x86_64+0x1004bd54a) in ViewLayer.needsMPVRender.setter+0x8a
==================
==================
WARNING: ThreadSanitizer: data race (pid=29731)
  Read of size 8 at 0x7b0800013d90 by thread T26:
    #0 VideoTime.second.getter <null>:2 (IINA:x86_64+0x10015a2ba)
    #1 PlayerCore.fileLoaded() <null>:2 (IINA:x86_64+0x1005d29b8)
    #2 MPVController.onFileLoaded() <null>:2 (IINA:x86_64+0x100645d59)
    #3 MPVController.handleEvent(_:) <null>:2 (IINA:x86_64+0x1006432a8)
    #4 closure #1 in MPVController.readEvents() <null>:2 (IINA:x86_64+0x100640d7b)
    #5 partial apply for closure #1 in MPVController.readEvents() <null>:2 (IINA:x86_64+0x1006619f9)
    #6 thunk for @escaping @callee_guaranteed () -> () <null>:2 (IINA:x86_64+0x100045752)
    #7 __tsan::invoke_and_release_block(void*) <null>:3 (libclang_rt.tsan_osx_dynamic.dylib:x86_64h+0x77f0b)
    #8 _dispatch_client_callout <null>:2 (libdispatch.dylib:x86_64+0x2657)
 
  Previous write of size 8 at 0x7b0800013d90 by main thread:
    #0 VideoTime.second.setter <null>:2 (IINA:x86_64+0x10015a31f)
    #1 PlayerCore.syncUI(_:) <null>:2 (IINA:x86_64+0x1005db14d)
    #2 PlayerCore.syncUITime() <null>:2 (IINA:x86_64+0x1005d8c9c)
    #3 @objc PlayerCore.syncUITime() <null>:2 (IINA:x86_64+0x1005d9641)
    #4 __NSFireTimer <null>:2 (Foundation:x86_64+0xbed69)
    #5 start <null>:2 (libdyld.dylib:x86_64+0x1acc8)
 
  Location is heap block of size 24 at 0x7b0800013d80 allocated by thread T26:
    #0 malloc <null>:3 (libclang_rt.tsan_osx_dynamic.dylib:x86_64h+0x532ec)
    #1 swift_slowAlloc <null>:2 (libswiftCore.dylib:x86_64+0x2f2ca8)
    #2 MPVController.onFileLoaded() <null>:2 (IINA:x86_64+0x100645940)
    #3 MPVController.handleEvent(_:) <null>:2 (IINA:x86_64+0x1006432a8)
    #4 closure #1 in MPVController.readEvents() <null>:2 (IINA:x86_64+0x100640d7b)
    #5 partial apply for closure #1 in MPVController.readEvents() <null>:2 (IINA:x86_64+0x1006619f9)
    #6 thunk for @escaping @callee_guaranteed () -> () <null>:2 (IINA:x86_64+0x100045752)
    #7 __tsan::invoke_and_release_block(void*) <null>:3 (libclang_rt.tsan_osx_dynamic.dylib:x86_64h+0x77f0b)
    #8 _dispatch_client_callout <null>:2 (libdispatch.dylib:x86_64+0x2657)
 
  Thread T26 (tid=955714, running) is a GCD worker thread
 
SUMMARY: ThreadSanitizer: data race (IINA:x86_64+0x10015a2ba) in VideoTime.second.getter+0x3a
==================
==================
WARNING: ThreadSanitizer: data race (pid=29731)
  Write of size 8 at 0x7b0800013ab0 by thread T26:
    #0 VideoTime.second.setter <null>:2 (IINA:x86_64+0x10015a31f)
    #1 PlayerCore.syncUI(_:) <null>:2 (IINA:x86_64+0x1005d9f67)
    #2 MPVController.handleEvent(_:) <null>:2 (IINA:x86_64+0x10064358c)
    #3 closure #1 in MPVController.readEvents() <null>:2 (IINA:x86_64+0x100640d7b)
    #4 partial apply for closure #1 in MPVController.readEvents() <null>:2 (IINA:x86_64+0x1006619f9)
    #5 thunk for @escaping @callee_guaranteed () -> () <null>:2 (IINA:x86_64+0x100045752)
    #6 __tsan::invoke_and_release_block(void*) <null>:3 (libclang_rt.tsan_osx_dynamic.dylib:x86_64h+0x77f0b)
    #7 _dispatch_client_callout <null>:2 (libdispatch.dylib:x86_64+0x2657)
 
  Previous write of size 8 at 0x7b0800013ab0 by main thread:
    #0 VideoTime.second.setter <null>:2 (IINA:x86_64+0x10015a31f)
    #1 PlayerCore.syncUI(_:) <null>:2 (IINA:x86_64+0x1005dae27)
    #2 PlayerCore.syncUITime() <null>:2 (IINA:x86_64+0x1005d8c9c)
    #3 @objc PlayerCore.syncUITime() <null>:2 (IINA:x86_64+0x1005d9641)
    #4 __NSFireTimer <null>:2 (Foundation:x86_64+0xbed69)
    #5 start <null>:2 (libdyld.dylib:x86_64+0x1acc8)
 
  Location is heap block of size 24 at 0x7b0800013aa0 allocated by thread T26:
    #0 malloc <null>:3 (libclang_rt.tsan_osx_dynamic.dylib:x86_64h+0x532ec)
    #1 swift_slowAlloc <null>:2 (libswiftCore.dylib:x86_64+0x2f2ca8)
    #2 MPVController.onFileLoaded() <null>:2 (IINA:x86_64+0x100645c7c)
    #3 MPVController.handleEvent(_:) <null>:2 (IINA:x86_64+0x1006432a8)
    #4 closure #1 in MPVController.readEvents() <null>:2 (IINA:x86_64+0x100640d7b)
    #5 partial apply for closure #1 in MPVController.readEvents() <null>:2 (IINA:x86_64+0x1006619f9)
    #6 thunk for @escaping @callee_guaranteed () -> () <null>:2 (IINA:x86_64+0x100045752)
    #7 __tsan::invoke_and_release_block(void*) <null>:3 (libclang_rt.tsan_osx_dynamic.dylib:x86_64h+0x77f0b)
    #8 _dispatch_client_callout <null>:2 (libdispatch.dylib:x86_64+0x2657)
 
  Thread T26 (tid=955714, running) is a GCD worker thread
 
SUMMARY: ThreadSanitizer: data race (IINA:x86_64+0x10015a31f) in VideoTime.second.setter+0x3f
==================
==================
WARNING: ThreadSanitizer: data race (pid=29731)
  Write of size 1 at 0x7b540000c3a8 by thread T22:
    #0 PlaybackInfo.isSeeking.setter <null>:2 (IINA:x86_64+0x10011f5de)
    #1 MPVController.handleEvent(_:) <null>:2 (IINA:x86_64+0x10064427e)
    #2 closure #1 in MPVController.readEvents() <null>:2 (IINA:x86_64+0x100640d7b)
    #3 partial apply for closure #1 in MPVController.readEvents() <null>:2 (IINA:x86_64+0x1006619f9)
    #4 thunk for @escaping @callee_guaranteed () -> () <null>:2 (IINA:x86_64+0x100045752)
    #5 __tsan::invoke_and_release_block(void*) <null>:3 (libclang_rt.tsan_osx_dynamic.dylib:x86_64h+0x77f0b)
    #6 _dispatch_client_callout <null>:2 (libdispatch.dylib:x86_64+0x2657)
 
  Previous read of size 1 at 0x7b540000c3a8 by main thread:
    #0 PlaybackInfo.isSeeking.getter <null>:2 (IINA:x86_64+0x10011f550)
    #1 MainWindowController.updateNetworkState() <null>:2 (IINA:x86_64+0x10027538e)
    #2 $s4IINA10PlayerCoreC6syncUIyyAC12SyncUIOptionOFyyScMYccfU0_ <null>:2 (IINA:x86_64+0x1005ddbd6)
    #3 $s4IINA10PlayerCoreC6syncUIyyAC12SyncUIOptionOFyyScMYccfU0_TA <null>:2 (IINA:x86_64+0x1005f4ce9)
    #4 thunk for @escaping @callee_guaranteed () -> () <null>:2 (IINA:x86_64+0x100045752)
    #5 __tsan::invoke_and_release_block(void*) <null>:3 (libclang_rt.tsan_osx_dynamic.dylib:x86_64h+0x77f0b)
    #6 _dispatch_client_callout <null>:2 (libdispatch.dylib:x86_64+0x2657)
    #7 start <null>:2 (libdyld.dylib:x86_64+0x1acc8)
 
  Location is heap block of size 616 at 0x7b540000c300 allocated by main thread:
    #0 malloc <null>:3 (libclang_rt.tsan_osx_dynamic.dylib:x86_64h+0x532ec)
    #1 swift_slowAlloc <null>:2 (libswiftCore.dylib:x86_64+0x2f2ca8)
    #2 PlayerCore.info.getter <null>:2 (IINA:x86_64+0x10059d049)
    #3 MPVController.mpvInit() <null>:2 (IINA:x86_64+0x1006295a0)
    #4 PlayerCore.startMPV() <null>:2 (IINA:x86_64+0x1005a89cb)
    #5 static PlayerCore.createPlayerCore() <null>:2 (IINA:x86_64+0x1005980cb)
    #6 $s4IINA10PlayerCoreC5first_WZ <null>:2 (IINA:x86_64+0x100597cc3)
    #7 dispatch_once <null>:3 (libclang_rt.tsan_osx_dynamic.dylib:x86_64h+0x78be3)
    #8 dispatch_once_f <null>:3 (libclang_rt.tsan_osx_dynamic.dylib:x86_64h+0x78ccb)
    #9 swift_once <null>:2 (libswiftCore.dylib:x86_64+0x31a839)
    #10 static PlayerCore.active.getter <null>:2 (IINA:x86_64+0x1005986fe)
    #11 AppDelegate.applicationDidFinishLaunching(_:) <null>:2 (IINA:x86_64+0x1003149ec)
    #12 @objc AppDelegate.applicationDidFinishLaunching(_:) <null>:2 (IINA:x86_64+0x100318e66)
    #13 __CFNOTIFICATIONCENTER_IS_CALLING_OUT_TO_AN_OBSERVER__ <null>:3 (CoreFoundation:x86_64h+0x7a14e)
    #14 start <null>:2 (libdyld.dylib:x86_64+0x1acc8)
 
  Thread T22 (tid=955442, running) is a GCD worker thread
 
SUMMARY: ThreadSanitizer: data race (IINA:x86_64+0x10011f5de) in PlaybackInfo.isSeeking.setter+0x5e
==================
==================
WARNING: ThreadSanitizer: data race (pid=29731)
  Read of size 1 at 0x7b10000f22b9 by thread T40 (mutexes: write M386038120195514024):
    #0 ViewLayer.forceRender.getter <null>:2 (IINA:x86_64+0x1004bd6d8)
    #1 ViewLayer.canDraw(inCGLContext:pixelFormat:forLayerTime:displayTime:) <null>:2 (IINA:x86_64+0x1004bf7fc)
    #2 @objc ViewLayer.canDraw(inCGLContext:pixelFormat:forLayerTime:displayTime:) <null>:2 (IINA:x86_64+0x1004bfc23)
    #3 CAOpenGLLayerDraw(CAOpenGLLayer*, double, CVTimeStamp const*, unsigned int) <null>:2 (QuartzCore:x86_64+0xc1fce)
    #4 @objc ViewLayer.display() <null>:2 (IINA:x86_64+0x1004c3641)
    #5 ViewLayer.draw(forced:) <null>:2 (IINA:x86_64+0x1004c2147)
    #6 closure #1 in mpvUpdateCallback(_:) <null>:2 (IINA:x86_64+0x10065af0d)
    #7 partial apply for closure #1 in mpvUpdateCallback(_:) <null>:2 (IINA:x86_64+0x1006621b9)
    #8 thunk for @escaping @callee_guaranteed () -> () <null>:2 (IINA:x86_64+0x100045752)
    #9 __tsan::invoke_and_release_block(void*) <null>:3 (libclang_rt.tsan_osx_dynamic.dylib:x86_64h+0x77f0b)
    #10 _dispatch_client_callout <null>:2 (libdispatch.dylib:x86_64+0x2657)
 
  Previous write of size 1 at 0x7b10000f22b9 by thread T22:
    #0 ViewLayer.forceRender.setter <null>:2 (IINA:x86_64+0x1004bd78a)
    #1 ViewLayer.draw(forced:) <null>:2 (IINA:x86_64+0x1004c211d)
    #2 PlayerCore.playbackRestarted() <null>:2 (IINA:x86_64+0x1005d40aa)
    #3 MPVController.handleEvent(_:) <null>:2 (IINA:x86_64+0x100644594)
    #4 closure #1 in MPVController.readEvents() <null>:2 (IINA:x86_64+0x100640d7b)
    #5 partial apply for closure #1 in MPVController.readEvents() <null>:2 (IINA:x86_64+0x1006619f9)
    #6 thunk for @escaping @callee_guaranteed () -> () <null>:2 (IINA:x86_64+0x100045752)
    #7 __tsan::invoke_and_release_block(void*) <null>:3 (libclang_rt.tsan_osx_dynamic.dylib:x86_64h+0x77f0b)
    #8 _dispatch_client_callout <null>:2 (libdispatch.dylib:x86_64+0x2657)
 
  Location is heap block of size 64 at 0x7b10000f2280 allocated by main thread:
    #0 calloc <null>:3 (libclang_rt.tsan_osx_dynamic.dylib:x86_64h+0x534a4)
    #1 _objc_rootAllocWithZone <null>:3 (libobjc.A.dylib:x86_64h+0x10804)
    #2 closure #1 in VideoView.videoLayer.getter <null>:2 (IINA:x86_64+0x1004de007)
    #3 VideoView.videoLayer.getter <null>:2 (IINA:x86_64+0x1004ddebf)
    #4 VideoView.init(frame:) <null>:2 (IINA:x86_64+0x1004e1593)
    #5 @objc VideoView.init(frame:) <null>:2 (IINA:x86_64+0x1004e1e05)
    #6 VideoView.__allocating_init(frame:player:) <null>:2 (IINA:x86_64+0x1004e1f53)
    #7 MainWindowController._videoView.getter <null>:2 (IINA:x86_64+0x1001f4251)
    #8 MainWindowController.videoView.getter <null>:2 (IINA:x86_64+0x1001f3e39)
    #9 MainWindowController.addVideoViewToWindow() <null>:2 (IINA:x86_64+0x1002258b1)
    #10 MainWindowController.windowDidLoad() <null>:2 (IINA:x86_64+0x100221307)
    #11 @objc MainWindowController.windowDidLoad() <null>:2 (IINA:x86_64+0x1002245a1)
    #12 -[NSWindowController _windowDidLoad] <null>:2 (AppKit:x86_64+0x23a72d)
    #13 PlayerCore.open(_:shouldAutoLoad:) <null>:2 (IINA:x86_64+0x1005a1894)
    #14 PlayerCore.openURLs(_:shouldAutoLoad:) <null>:2 (IINA:x86_64+0x1005a2480)
    #15 PlayerCore.openURL(_:shouldAutoLoad:) <null>:2 (IINA:x86_64+0x1005a2d25)
    #16 OpenURLWindowController.openBtnAction(_:) <null>:2 (IINA:x86_64+0x1004962d7)
    #17 @objc OpenURLWindowController.openBtnAction(_:) <null>:2 (IINA:x86_64+0x10049654f)
    #18 -[NSApplication(NSResponder) sendAction:to:from:] <null>:2 (AppKit:x86_64+0x283cf6)
    #19 start <null>:2 (libdyld.dylib:x86_64+0x1acc8)
 
  Mutex M386038120195514024 is already destroyed.
 
  Thread T40 (tid=955817, running) is a GCD worker thread
 
  Thread T22 (tid=955442, running) is a GCD worker thread
 
SUMMARY: ThreadSanitizer: data race (IINA:x86_64+0x1004bd6d8) in ViewLayer.forceRender.getter+0x68
==================
ThreadSanitizer: reported 5 warnings
 
Performing @selector(terminate:) from sender NSMenuItem 0x7b1c0001a240
abort() called

Thread 0 Crashed:: Dispatch queue: com.apple.main-thread
0   libsystem_kernel.dylib        	0x00007fff6ea2c32a __pthread_kill + 10
1   libsystem_pthread.dylib       	0x00007fff6eae8e60 pthread_kill + 430
2   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b1a33e wrap_pthread_kill + 302
3   libsystem_c.dylib             	0x00007fff6e9b3808 abort + 120
4   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b00806 __sanitizer::Abort() + 70
5   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111afff34 __sanitizer::Die() + 196
6   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b2f063 __tsan::finalize(void*) + 67
7   libsystem_c.dylib             	0x00007fff6e98e13c __cxa_finalize_ranges + 319
8   libsystem_c.dylib             	0x00007fff6e98e412 exit + 55
9   com.apple.AppKit              	0x00007fff321a3994 -[NSApplication terminate:] + 1749
10  com.apple.AppKit              	0x00007fff32118cf7 -[NSApplication(NSResponder) sendAction:to:from:] + 299
11  com.apple.AppKit              	0x00007fff3222878e -[NSMenuItem _corePerformAction] + 312
12  com.apple.AppKit              	0x00007fff3222850a -[NSCarbonMenuImpl performActionWithHighlightingForItemAtIndex:] + 106
13  com.apple.AppKit              	0x00007fff32279098 -[NSMenu performActionForItemAtIndex:] + 114
14  com.apple.AppKit              	0x00007fff3227901d -[NSMenu _internalPerformActionForItemAtIndex:] + 82
15  com.apple.AppKit              	0x00007fff32278e67 -[NSCarbonMenuImpl _carbonCommandProcessEvent:handlerCallRef:] + 101
16  com.apple.AppKit              	0x00007fff32209580 NSSLMMenuEventHandler + 908
17  com.apple.HIToolbox           	0x00007fff338668ef DispatchEventToHandlers(EventTargetRec*, OpaqueEventRef*, HandlerCallRec*) + 1254
18  com.apple.HIToolbox           	0x00007fff33865d7d SendEventToEventTargetInternal(OpaqueEventRef*, OpaqueEventTargetRef*, HandlerCallRec*) + 329
19  com.apple.HIToolbox           	0x00007fff3387b46e SendEventToEventTarget + 39
20  com.apple.HIToolbox           	0x00007fff338db3eb SendHICommandEvent(unsigned int, HICommand const*, unsigned int, unsigned int, unsigned char, void const*, OpaqueEventTargetRef*, OpaqueEventTargetRef*, OpaqueEventRef**) + 368
21  com.apple.HIToolbox           	0x00007fff33902045 SendMenuCommandWithContextAndModifiers + 45
22  com.apple.HIToolbox           	0x00007fff33901fed SendMenuItemSelectedEvent + 346
23  com.apple.HIToolbox           	0x00007fff33901e39 FinishMenuSelection(SelectionData*, MenuResult*, MenuResult*) + 96
24  com.apple.HIToolbox           	0x00007fff3390286e MenuSelectCore(MenuData*, Point, double, unsigned int, OpaqueMenuRef**, unsigned short*) + 603
25  com.apple.HIToolbox           	0x00007fff33902578 _HandleMenuSelection2 + 460
26  com.apple.AppKit              	0x00007fff320ad15d _NSHandleCarbonMenuEvent + 215
27  com.apple.AppKit              	0x00007fff320acfca _DPSEventHandledByCarbon + 54
28  com.apple.AppKit              	0x00007fff31ed54ea -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 2962
29  com.apple.AppKit              	0x00007fff31ec6bae -[NSApplication run] + 658
30  com.apple.AppKit              	0x00007fff31e98996 NSApplicationMain + 777
31  com.colliderli.iina           	0x000000010f285104 main + 36
32  libdyld.dylib                 	0x00007fff6e8e4cc9 start + 1

Thread 1:
0   libsystem_kernel.dylib        	0x00007fff6ea28746 __semwait_signal + 10
1   libsystem_c.dylib             	0x00007fff6e9abeea nanosleep + 196
2   libsystem_c.dylib             	0x00007fff6e9abde4 usleep + 53
3   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b5258a __tsan::BackgroundThread(void*) + 474
4   libsystem_pthread.dylib       	0x00007fff6eae9109 _pthread_start + 148
5   libsystem_pthread.dylib       	0x00007fff6eae4b8b thread_start + 15

Thread 2:: mpv/mpv core
0   libsystem_kernel.dylib        	0x00007fff6ea28872 __psynch_cvwait + 10
1   libsystem_pthread.dylib       	0x00007fff6eae9425 _pthread_cond_wait + 698
2   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b6249e __tsan::call_pthread_cancel_with_cleanup(int (*)(void*), void (*)(void*), void*) + 62
3   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b17635 wrap_pthread_cond_timedwait + 549
4   libmpv.1.dylib                	0x0000000110225b79 mp_dispatch_queue_process + 345
5   libmpv.1.dylib                	0x0000000110261d48 mp_wait_events + 88
6   libmpv.1.dylib                	0x000000011023e311 mp_shutdown_clients + 113
7   libmpv.1.dylib                	0x000000011023e606 core_thread + 70
8   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b16b0d __tsan_thread_start_func + 141
9   libsystem_pthread.dylib       	0x00007fff6eae9109 _pthread_start + 148
10  libsystem_pthread.dylib       	0x00007fff6eae4b8b thread_start + 15

Thread 3:: mpv/log-file
0   libsystem_kernel.dylib        	0x00007fff6ea28872 __psynch_cvwait + 10
1   libsystem_pthread.dylib       	0x00007fff6eae9425 _pthread_cond_wait + 698
2   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b6249e __tsan::call_pthread_cancel_with_cleanup(int (*)(void*), void (*)(void*), void*) + 62
3   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b173ad wrap_pthread_cond_wait + 525
4   libmpv.1.dylib                	0x00000001101e732b log_file_thread + 75
5   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b16b0d __tsan_thread_start_func + 141
6   libsystem_pthread.dylib       	0x00007fff6eae9109 _pthread_start + 148
7   libsystem_pthread.dylib       	0x00007fff6eae4b8b thread_start + 15

Thread 4:: AMCP Logging Spool
0   libsystem_kernel.dylib        	0x00007fff6ea25e26 semaphore_wait_trap + 10
1   com.apple.audio.caulk         	0x00007fff684b6b16 caulk::mach::semaphore::wait() + 16
2   com.apple.audio.caulk         	0x00007fff684b69b2 caulk::semaphore::timed_wait(double) + 106
3   com.apple.audio.caulk         	0x00007fff684b67c4 caulk::concurrent::details::worker_thread::run() + 30
4   com.apple.audio.caulk         	0x00007fff684b61e4 void* caulk::thread_proxy<std::__1::tuple<caulk::thread::attributes, void (caulk::concurrent::details::worker_thread::*)(), std::__1::tuple<caulk::concurrent::details::worker_thread*> > >(void*) + 45
5   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b16b0d __tsan_thread_start_func + 141
6   libsystem_pthread.dylib       	0x00007fff6eae9109 _pthread_start + 148
7   libsystem_pthread.dylib       	0x00007fff6eae4b8b thread_start + 15

Thread 5:
0   libsystem_kernel.dylib        	0x00007fff6ea25e26 semaphore_wait_trap + 10
1   com.apple.audio.caulk         	0x00007fff684b6b16 caulk::mach::semaphore::wait() + 16
2   com.apple.audio.caulk         	0x00007fff684b69b2 caulk::semaphore::timed_wait(double) + 106
3   com.apple.audio.caulk         	0x00007fff684b67c4 caulk::concurrent::details::worker_thread::run() + 30
4   com.apple.audio.caulk         	0x00007fff684b61e4 void* caulk::thread_proxy<std::__1::tuple<caulk::thread::attributes, void (caulk::concurrent::details::worker_thread::*)(), std::__1::tuple<caulk::concurrent::details::worker_thread*> > >(void*) + 45
5   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b16b0d __tsan_thread_start_func + 141
6   libsystem_pthread.dylib       	0x00007fff6eae9109 _pthread_start + 148
7   libsystem_pthread.dylib       	0x00007fff6eae4b8b thread_start + 15

Thread 6:: com.apple.NSEventThread
0   libsystem_kernel.dylib        	0x00007fff6ea25dea mach_msg_trap + 10
1   libsystem_kernel.dylib        	0x00007fff6ea26160 mach_msg + 60
2   com.apple.CoreFoundation      	0x00007fff34c63825 __CFRunLoopServiceMachPort + 247
3   com.apple.CoreFoundation      	0x00007fff34c622f2 __CFRunLoopRun + 1319
4   com.apple.CoreFoundation      	0x00007fff34c6176e CFRunLoopRunSpecific + 462
5   com.apple.AppKit              	0x00007fff32077ea4 _NSEventThread + 132
6   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b16b0d __tsan_thread_start_func + 141
7   libsystem_pthread.dylib       	0x00007fff6eae9109 _pthread_start + 148
8   libsystem_pthread.dylib       	0x00007fff6eae4b8b thread_start + 15

Thread 7:: LocalStorage
0   libsystem_kernel.dylib        	0x00007fff6ea28872 __psynch_cvwait + 10
1   libsystem_pthread.dylib       	0x00007fff6eae9425 _pthread_cond_wait + 698
2   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b6249e __tsan::call_pthread_cancel_with_cleanup(int (*)(void*), void (*)(void*), void*) + 62
3   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b173ad wrap_pthread_cond_wait + 525
4   com.apple.JavaScriptCore      	0x00007fff393f6402 WTF::ParkingLot::parkConditionallyImpl(void const*, WTF::ScopedLambda<bool ()> const&, WTF::ScopedLambda<void ()> const&, WTF::TimeWithDynamicClockType const&) + 3858
5   com.apple.WebKitLegacy        	0x00007fff457c83f5 bool WTF::Condition::waitUntil<WTF::Lock>(WTF::Lock&, WTF::TimeWithDynamicClockType const&) + 165
6   com.apple.WebKitLegacy        	0x00007fff457cb5e1 std::__1::unique_ptr<WTF::Function<void ()>, std::__1::default_delete<WTF::Function<void ()> > > WTF::MessageQueue<WTF::Function<void ()> >::waitForMessageFilteredWithTimeout<WTF::MessageQueue<WTF::Function<void ()> >::waitForMessage()::'lambda'(WTF::Function<void ()> const&)>(WTF::MessageQueueWaitResult&, WTF::MessageQueue<WTF::Function<void ()> >::waitForMessage()::'lambda'(WTF::Function<void ()> const&)&&, WTF::Seconds) + 161
7   com.apple.WebKitLegacy        	0x00007fff457cad26 WebCore::StorageThread::threadEntryPoint() + 86
8   com.apple.JavaScriptCore      	0x00007fff39410e3f WTF::Thread::entryPoint(WTF::Thread::NewThreadContext*) + 223
9   com.apple.JavaScriptCore      	0x00007fff384ddbf9 WTF::wtfThreadEntryPoint(void*) + 9
10  libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b16b0d __tsan_thread_start_func + 141
11  libsystem_pthread.dylib       	0x00007fff6eae9109 _pthread_start + 148
12  libsystem_pthread.dylib       	0x00007fff6eae4b8b thread_start + 15

Thread 8:
0   libsystem_pthread.dylib       	0x00007fff6eae4b68 start_wqthread + 0

Thread 9:
0   libsystem_pthread.dylib       	0x00007fff6eae4b68 start_wqthread + 0

Thread 10:
0   libsystem_pthread.dylib       	0x00007fff6eae4b68 start_wqthread + 0

Thread 11:: Dispatch queue: com.colliderli.iina.controller
0   libsystem_kernel.dylib        	0x00007fff6ea28872 __psynch_cvwait + 10
1   libsystem_pthread.dylib       	0x00007fff6eae9425 _pthread_cond_wait + 698
2   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b6249e __tsan::call_pthread_cancel_with_cleanup(int (*)(void*), void (*)(void*), void*) + 62
3   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b173ad wrap_pthread_cond_wait + 525
4   com.apple.Foundation          	0x00007fff372f094b -[NSOperation waitUntilFinished] + 697
5   com.apple.Foundation          	0x00007fff372d505b -[__NSObserver _doit:] + 239
6   com.apple.CoreFoundation      	0x00007fff34c5914f __CFNOTIFICATIONCENTER_IS_CALLING_OUT_TO_AN_OBSERVER__ + 12
7   com.apple.CoreFoundation      	0x00007fff34c590e3 ___CFXRegistrationPost1_block_invoke + 63
8   com.apple.CoreFoundation      	0x00007fff34c59058 _CFXRegistrationPost1 + 372
9   com.apple.CoreFoundation      	0x00007fff34c58cc4 ___CFXNotificationPost_block_invoke + 80
10  com.apple.CoreFoundation      	0x00007fff34c28e2d -[_CFXNotificationRegistrar find:object:observer:enumerator:] + 1554
11  com.apple.CoreFoundation      	0x00007fff34c282d9 _CFXNotificationPost + 1351
12  com.colliderli.iina           	0x000000010f546fdc PlayerCore.postNotification(_:) + 428
13  com.colliderli.iina           	0x000000010f5ade08 MPVController.handlePropertyChange(_:_:) + 36024
14  com.colliderli.iina           	0x000000010f5a06f3 MPVController.handleEvent(_:) + 6467
15  com.colliderli.iina           	0x000000010f59ed7c closure #1 in MPVController.readEvents() + 556
16  com.colliderli.iina           	0x000000010f5bf9fa partial apply for closure #1 in MPVController.readEvents() + 26
17  com.colliderli.iina           	0x000000010efa3753 thunk for @escaping @callee_guaranteed () -> () + 83
18  libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b62f0c __tsan::invoke_and_release_block(void*) + 12
19  libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b62c66 __tsan::dispatch_callback_wrap(void*) + 310
20  libdispatch.dylib             	0x00007fff6e88b658 _dispatch_client_callout + 8
21  libdispatch.dylib             	0x00007fff6e890c44 _dispatch_lane_serial_drain + 597
22  libdispatch.dylib             	0x00007fff6e8915d6 _dispatch_lane_invoke + 363
23  libdispatch.dylib             	0x00007fff6e89ac09 _dispatch_workloop_worker_thread + 596
24  libsystem_pthread.dylib       	0x00007fff6eae5a3d _pthread_wqthread + 290
25  libsystem_pthread.dylib       	0x00007fff6eae4b77 start_wqthread + 15

Thread 12:: mpv/worker
0   libsystem_kernel.dylib        	0x00007fff6ea28872 __psynch_cvwait + 10
1   libsystem_pthread.dylib       	0x00007fff6eae9425 _pthread_cond_wait + 698
2   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b6249e __tsan::call_pthread_cancel_with_cleanup(int (*)(void*), void (*)(void*), void*) + 62
3   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b173ad wrap_pthread_cond_wait + 525
4   libmpv.1.dylib                	0x00000001102276fc worker_thread + 76
5   libclang_rt.tsan_osx_dynamic.dylib	0x0000000111b16b0d __tsan_thread_start_func + 141
6   libsystem_pthread.dylib       	0x00007fff6eae9109 _pthread_start + 148
7   libsystem_pthread.dylib       	0x00007fff6eae4b8b thread_start + 15

Thread 0 crashed with X86 Thread State (64-bit):
  rax: 0x0000000000000000  rbx: 0x000000011a4f7dc0  rcx: 0x00007ffee0ca0a08  rdx: 0x0000000000000000
  rdi: 0x0000000000000307  rsi: 0x0000000000000006  rbp: 0x00007ffee0ca0a30  rsp: 0x00007ffee0ca0a08
   r8: 0x0000000000000000   r9: 0x0000000000000000  r10: 0x000000011a4f7dc0  r11: 0x0000000000000246
  r12: 0x0000000000000307  r13: 0x0000000000000000  r14: 0x0000000000000006  r15: 0x0000000000000016
  rip: 0x00007fff6ea2c32a  rfl: 0x0000000000000246  cr2: 0x00001c4000004100
  
Logical CPU:     0
Error Code:      0x02000148
Trap Number:     133
...
Truncated to not exceed GitHub limits...

Steps to reproduce:

In Xcode 13.4 edit the scheme and enable:
- Thread Sanitizer
- Undefined Behavior Sanitizer
Build IINA
Take the application to a slow Mac running macOS 10.15.7
Play a video
Usually the thread sanitizer will detect issues

[x] MPV does not have this problem.

This is an issue with IINA code.

How often does this happen? Usually.

Jun 14 '22 02:06 low-batt

The VideoTime class is just a simple data structure, which shouldn't generally be put into the position of having to deal with concurrency. So that compelled me to dig into the code (just a bit) to see why this warning was happening.

Maybe this is off-topic for this issue, but I saw that VideoTime gets a lot of concurrent use is in the PlaybackHistory class, which is a bigger data structure... which soon leads to HistoryController, which looks like an (or the?) in-memory data store for playback history. I didn't realize I was browsing on the plugin-system branch. Its version of HistoryController has an actual DispatchQueue (see the diff): https://github.com/iina/iina/blob/0bc3bf07680f9d8b81ddd7f66067f0cd4b376134/iina/HistoryController.swift#L13

But it is only used outside the class, to protect HistoryController.shared.add() (see the diff)

https://github.com/iina/iina/blob/c33ced3500630c02f0671e8b5b2f2ab264b77180/iina/PlayerCore.swift#L1336-L1344

There is no synchronization protection for this class on the develop branch. This looks like a smoking gun.

Adding a DispatchQueue was an improvement but it should protect all the methods in HistoryController (except for the constructor). And I'd also recommend encapsulating it inside the class: keep it private and only use it inside the class. Reusing DQs across files gets super confusing super quickly and often leads to deadlock. Also, having lots of DQs almost always leads to better performance, not worse, than fewer.

For classes like these, I've found the following pattern is useful:

For any data store or repository-style class, give it a private serial DispatchQueue (it's serial by default, unless you supply attributes: .concurrent. DispatchQueue.main is serial as well)
Make all class variables private as well. Allow access only via public CRUD operations, which internally have all their logic inside dq.sync { } blocks. For example:

  class HistoryController: NSObject {

  // ...

  private var dq = DispatchQueue(label: "IINAHistoryController", qos: .background)

  // ...

  public func save() {
    dq.sync {
      saveUnprotected()
    }
  }

  private func saveUnprotected() {
    let result = NSKeyedArchiver.archiveRootObject(history, toFile: plistURL.path)
    if !result {
      Logger.log("Cannot save playback history!", level: .error)
    }
    NotificationCenter.default.post(Notification(name: .iinaHistoryUpdated))
  }

  public func remove(_ entries: [PlaybackHistory]) {
    dq.sync {
      history = history.filter { !entries.contains($0) }
      saveUnprotected()
    }
  }

Going back to PlayerCore, I also see that DispatchQueue.main.sync is used in some places where a custom private DispatchQueue would be better (sparing DispatchQueue.main for when UI code is immediately needed) like here: https://github.com/iina/iina/blob/2a024281b64c6f52c84aec8e4c5c01978422514c/iina/PlayerCore.swift#L1227-L1248

Recommend putting

Jun 14 '22 05:06 svobs

There is history regarding this...

I noticed a lot of issues with multiple threads accessing shared data when looking into an issue quite a while back. At that time I decided not to open that can of worms expecting that it would be better to wait for support from Xcode for the latest version of Swift that adds concurrency features like actor. Also at that time the Xcode thread sanitizer seemed to be malfunctioning. I fixed that issue with a "spot" fix that only addressed the issue at hand. In PlaybackInfo you can see that spot fix:

  // Queue dedicated to providing serialized access to class data shared between threads.
  // Data is accessed by the main thread, therefore the QOS for the queue must not be too low
  // to avoid blocking the main thread for an extended period of time.
  private let lockQueue = DispatchQueue(label: "IINAPlaybackInfoLock", qos: .userInitiated)

  func calculateTotalDuration() -> Double? {
    lockQueue.sync {
      var totalDuration: Double? = 0
      for p in playlist {
        if let duration = cachedVideoDurationAndProgress[p.filename]?.duration {
          totalDuration! += duration > 0 ? duration : 0
        } else {
          // Cache is missing an entry, can't provide a total.
          return nil
        }
      }
      return totalDuration
    }
  }

Fast forward to today. Xcode 13 supports the Swift concurrently features, but that support uses macOS features that were added in 10.15. Trying to use an actor would require such extensive conditionalization to support earlier versions of macOS that I think that feature is not usable.

What prompted this issue being entered is a search for what triggered the crash in issue #3822. So far tests with the Xcode sanitizer did not reveal something that might explain that crash, so I entered what it did find as separate issues.

For the moment I am turning my attention to the plugin system review as we need to get that merged. Then I will come back to these thread issues. With the new Macs having more cores and other kinds of concurrency enhancements we need to make sure IINA is fully following best practices for threading. Time to open this can of worms in my opinion.

Jun 14 '22 18:06 low-batt

Great! Yeah, I have always wanted to use actors too. But alas still have not had a chance to use it. I hope it sees more widespread adoption over time.

For the moment I am turning my attention to the plugin system review as we need to get that merged. Then I will come back to these thread issues.

Sounds like a good plan.

Time to open this can of worms in my opinion.

Or...pull on this thread? 🙃

Jun 15 '22 04:06 svobs

I would really recommend using a private, explicitly allocated os_unfair_lock for this. To ensure it is used correctly I would suggest moving it into our utilities and then exposing an API equivalent to the new OSAllocatedUnfairLock.

Jun 15 '22 06:06 saagarjha

@saagarjha I planned on asking how we wanted to do locking before starting to code fixes. I had not brought this up yet as I need to focus on other stuff at the moment. I plan on coming back to these thread issues as soon as the plugin system is merged and we start merging other fixes.

Although coded by me the above GCD based locking pattern did not originate from me and is not my preferred way of coordinating threads. That was coded back in August last year when I was learning Swift and reading about Swift Best Practices. There are Swift developers that preach that OS locks are "dangerous" and a DispatchQueue should be used instead and is less error prone. Seems to me you can still run into issues such as deadlocks with the DispatchQueue based pattern.

I believe the DispatchQueue pattern does offer one advantage. In a thread dump you can see what code is "holding" a lock by the stack trace of the thread for the "lock" queue. Whereas for OS locks you can see the threads waiting for the lock, but it is not immediately apparent which thread owns the lock. However I don't think that is a compelling reason to choose it.

I will definitely coordinate with you on this, but need to focus elsewhere at the moment...

Jun 15 '22 18:06 low-batt

Dispatch queues should be isomorphic if implemented correctly but definitely have more overhead, so we should avoid them in the places we can. Let me know when you want to circle back on this and we can work through a strategy together :)

Jun 17 '22 09:06 saagarjha