CommandPost / CommandPost

Workflow Enhancements for Creatives
https://commandpost.io
MIT License
426 stars 37 forks source link

Freeze when adding media via Media Watch Folder Notification #2162

Open latenitefilms opened 4 years ago

latenitefilms commented 4 years ago

See video here.

@randomeizer - You've already Rx-ifed the Media Watch Folder code, so curious as to what might be getting stuck in a notification loop? Anything obvious jump out at you in the code?

I can't reproduce the freeze on my machine yet.

latenitefilms commented 4 years ago

Actually... I can reproduce when I press "All Files". Interestingly, when I force quit CommandPost, the files are actually on the FCPX timeline.

latenitefilms commented 4 years ago

Crash log from when I force quit:

Command:         CommandPost
Path:            /Users/USER/*/CommandPost.app/Contents/MacOS/CommandPost
Identifier:      org.latenitefilms.CommandPost
Version:         1.0.2 (5686)
Parent:          launchd [1]
PID:             44420

Event:           hang
Duration:        1.10s (process was unresponsive for 34 seconds before sampling)
Steps:           11 (100ms sampling interval)

Hardware model:  MacBookPro14,3
Active cpus:     8

Time Awake Since Boot: 140000s
Time Since Wake: 5000s

Fan speed:       2154 rpm

--------------------------------------------------
Timeline format: stacks are sorted chronologically
Use -i and -heavy to re-report with count sorting
--------------------------------------------------

Heaviest stack for the main thread of the target process:
  11  start + 1 (libdyld.dylib + 91093) [0x7fff75c713d5]
  11  NSApplicationMain + 777 (AppKit + 10984) [0x7fff472d1ae8]
  11  -[NSApplication run] + 699 (AppKit + 79272) [0x7fff472e25a8]
  11  -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 1361 (AppKit + 103563) [0x7fff472e848b]
  11  _DPSNextEvent + 1135 (AppKit + 108445) [0x7fff472e979d]
  11  _BlockUntilNextEventMatchingListInModeWithFilter + 64 (HIToolbox + 44150) [0x7fff48f50c76]
  11  ReceiveNextEventCommon + 603 (HIToolbox + 44773) [0x7fff48f50ee5]
  11  RunCurrentEventLoopInMode + 292 (HIToolbox + 45483) [0x7fff48f511ab]
  11  CFRunLoopRunSpecific + 455 (CoreFoundation + 237246) [0x7fff49cf1ebe]
  11  __CFRunLoopRun + 2772 (CoreFoundation + 240612) [0x7fff49cf2be4]
  11  __CFRunLoopDoBlocks + 394 (CoreFoundation + 241287) [0x7fff49cf2e87]
  11  __CFRUNLOOP_IS_CALLING_OUT_TO_A_BLOCK__ + 12 (CoreFoundation + 489316) [0x7fff49d2f764]
  11  ___LSScheduleNotificationFunction_block_invoke_2 + 47 (LaunchServices + 237967) [0x7fff4b2ef18f]
  11  applicationStatusSubsystemCallback + 758 (AppKit + 2491710) [0x7fff4752f53e]
  11  -[NSNotificationCenter postNotificationName:object:userInfo:] + 66 (Foundation + 72363) [0x7fff4bf4baab]
  11  _CFXNotificationPost + 732 (CoreFoundation + 56423) [0x7fff49cc5c67]
  11  -[_CFXNotificationRegistrar find:object:observer:enumerator:] + 1642 (CoreFoundation + 59572) [0x7fff49cc68b4]
  11  ___CFXNotificationPost_block_invoke + 87 (CoreFoundation + 679720) [0x7fff49d5df28]
  11  _CFXRegistrationPost + 404 (CoreFoundation + 645754) [0x7fff49d55a7a]
  11  ___CFXRegistrationPost_block_invoke + 63 (CoreFoundation + 645904) [0x7fff49d55b10]
  11  __CFNOTIFICATIONCENTER_IS_CALLING_OUT_TO_AN_OBSERVER__ + 12 (CoreFoundation + 646038) [0x7fff49d55b96]
  11  -[AppWatcher applicationActivated:] + 65 (watcher.m:135,5 in watcher.so + 4737) [0x1125e2281]
  11  -[AppWatcher callback:withEvent:] + 578 (watcher.m:110,5 in watcher.so + 4180) [0x1125e2054]
  11  -[LuaSkin protectedCallAndError:nargs:nresults:] + 55 (Skin.m:262,19 in LuaSkin + 10957) [0x10d6f6acd]
  11  -[LuaSkin protectedCallAndTraceback:nresults:] + 203 (Skin.m:251,9 in LuaSkin + 10776) [0x10d6f6a18]
  11  lua_pcallk + 236 (lapi.c:969,14 in LuaSkin + 106016) [0x10d70de20]
  11  luaD_pcall + 110 (ldo.c:156,3 in LuaSkin + 132816) [0x10d7146d0]
  11  luai_objcttry + 28 (lobjectivec_exceptions.m:84,3 in LuaSkin + 49106) [0x10d6fffd2]
  11  luaD_callnoyield + 21 (ldo.c:526,3 in LuaSkin + 131539) [0x10d7141d3]
  11  luaD_call + 64 (ldo.c:516,5 in LuaSkin + 131474) [0x10d714192]
  11  luaV_execute + 708 (lvm.c:1134,13 in LuaSkin + 115156) [0x10d7101d4]
  11  luaD_precall + 681 (ldo.c:451,11 in LuaSkin + 131108) [0x10d714024]
  11  application_getMenus + 343 (internal.m:1091,21 in internal.so + 14891) [0x1125eea2b]
  11  _getMenuStructure + 1055 (internal.m:1025,34 in internal.so + 6324) [0x1125ec8b4]
  11  _getMenuStructure + 264 (internal.m:961,14 in internal.so + 5533) [0x1125ec59d]
  11  AXUIElementCopyMultipleAttributeValues + 730 (HIServices + 131991) [0x7fff484e5397]
  11  _AXMIGCopyMultipleAttributeValues + 400 (HIServices + 187859) [0x7fff484f2dd3]
  11  mach_msg_trap + 10 (libsystem_kernel.dylib + 4650) [0x7fff75da622a]
 *11  ipc_mqueue_receive_continue + 0 (kernel + 1651872) [0xffffff80003934a0]

Process:         CommandPost [44420]
UUID:            7E99A1F7-44E5-34FB-8C50-2EB1EE3BCC14
Path:            /Users/USER/*/CommandPost.app/Contents/MacOS/CommandPost
Architecture:    x86_64
Parent:          launchd [1]
UID:             501
Footprint:       116.12 MB
Start time:      2019-12-01 20:49:02 +1100
End time:        2019-12-01 20:49:03 +1100
Num samples:     11 (1-11)
CPU Time:        <0.001s (96.4K cycles, 22.4K instructions, 4.29c/i)
Note:            Unresponsive for 34 seconds before sampling
Note:            1 idle work queue thread omitted

  Thread 0x38fbea           DispatchQueue 1           11 samples (1-11)         priority 46 (base 46)
  <thread QoS user interactive (requested user interactive), process unclamped, process received importance donation from WindowServer [214], process received importance donation from pboard [320], process received importance donation from usernoted [352], IO tier 0>
  11  start + 1 (libdyld.dylib + 91093) [0x7fff75c713d5] 1-11
    11  NSApplicationMain + 777 (AppKit + 10984) [0x7fff472d1ae8] 1-11
      11  -[NSApplication run] + 699 (AppKit + 79272) [0x7fff472e25a8] 1-11
        11  -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 1361 (AppKit + 103563) [0x7fff472e848b] 1-11
          11  _DPSNextEvent + 1135 (AppKit + 108445) [0x7fff472e979d] 1-11
            11  _BlockUntilNextEventMatchingListInModeWithFilter + 64 (HIToolbox + 44150) [0x7fff48f50c76] 1-11
              11  ReceiveNextEventCommon + 603 (HIToolbox + 44773) [0x7fff48f50ee5] 1-11
                11  RunCurrentEventLoopInMode + 292 (HIToolbox + 45483) [0x7fff48f511ab] 1-11
                  11  CFRunLoopRunSpecific + 455 (CoreFoundation + 237246) [0x7fff49cf1ebe] 1-11
                    11  __CFRunLoopRun + 2772 (CoreFoundation + 240612) [0x7fff49cf2be4] 1-11
                      11  __CFRunLoopDoBlocks + 394 (CoreFoundation + 241287) [0x7fff49cf2e87] 1-11
                        11  __CFRUNLOOP_IS_CALLING_OUT_TO_A_BLOCK__ + 12 (CoreFoundation + 489316) [0x7fff49d2f764] 1-11
                          11  ___LSScheduleNotificationFunction_block_invoke_2 + 47 (LaunchServices + 237967) [0x7fff4b2ef18f] 1-11
                            11  applicationStatusSubsystemCallback + 758 (AppKit + 2491710) [0x7fff4752f53e] 1-11
                              11  -[NSNotificationCenter postNotificationName:object:userInfo:] + 66 (Foundation + 72363) [0x7fff4bf4baab] 1-11
                                11  _CFXNotificationPost + 732 (CoreFoundation + 56423) [0x7fff49cc5c67] 1-11
                                  11  -[_CFXNotificationRegistrar find:object:observer:enumerator:] + 1642 (CoreFoundation + 59572) [0x7fff49cc68b4] 1-11
                                    11  ___CFXNotificationPost_block_invoke + 87 (CoreFoundation + 679720) [0x7fff49d5df28] 1-11
                                      11  _CFXRegistrationPost + 404 (CoreFoundation + 645754) [0x7fff49d55a7a] 1-11
                                        11  ___CFXRegistrationPost_block_invoke + 63 (CoreFoundation + 645904) [0x7fff49d55b10] 1-11
                                          11  __CFNOTIFICATIONCENTER_IS_CALLING_OUT_TO_AN_OBSERVER__ + 12 (CoreFoundation + 646038) [0x7fff49d55b96] 1-11
                                            11  -[AppWatcher applicationActivated:] + 65 (watcher.m:135,5 in watcher.so + 4737) [0x1125e2281] 1-11
                                              11  -[AppWatcher callback:withEvent:] + 578 (watcher.m:110,5 in watcher.so + 4180) [0x1125e2054] 1-11
                                                11  -[LuaSkin protectedCallAndError:nargs:nresults:] + 55 (Skin.m:262,19 in LuaSkin + 10957) [0x10d6f6acd] 1-11
                                                  11  -[LuaSkin protectedCallAndTraceback:nresults:] + 203 (Skin.m:251,9 in LuaSkin + 10776) [0x10d6f6a18] 1-11
                                                    11  lua_pcallk + 236 (lapi.c:969,14 in LuaSkin + 106016) [0x10d70de20] 1-11
                                                      11  luaD_pcall + 110 (ldo.c:156,3 in LuaSkin + 132816) [0x10d7146d0] 1-11
                                                        11  luai_objcttry + 28 (lobjectivec_exceptions.m:84,3 in LuaSkin + 49106) [0x10d6fffd2] 1-11
                                                          11  luaD_callnoyield + 21 (ldo.c:526,3 in LuaSkin + 131539) [0x10d7141d3] 1-11
                                                            11  luaD_call + 64 (ldo.c:516,5 in LuaSkin + 131474) [0x10d714192] 1-11
                                                              11  luaV_execute + 708 (lvm.c:1134,13 in LuaSkin + 115156) [0x10d7101d4] 1-11
                                                                11  luaD_precall + 681 (ldo.c:451,11 in LuaSkin + 131108) [0x10d714024] 1-11
                                                                  11  application_getMenus + 343 (internal.m:1091,21 in internal.so + 14891) [0x1125eea2b] 1-11
                                                                    11  _getMenuStructure + 1055 (internal.m:1025,34 in internal.so + 6324) [0x1125ec8b4] 1-11
                                                                      11  _getMenuStructure + 264 (internal.m:961,14 in internal.so + 5533) [0x1125ec59d] 1-11
                                                                        11  AXUIElementCopyMultipleAttributeValues + 730 (HIServices + 131991) [0x7fff484e5397] 1-11
                                                                          11  _AXMIGCopyMultipleAttributeValues + 400 (HIServices + 187859) [0x7fff484f2dd3] 1-11
                                                                            11  mach_msg_trap + 10 (libsystem_kernel.dylib + 4650) [0x7fff75da622a] 1-11
                                                                             *11  ipc_mqueue_receive_continue + 0 (kernel + 1651872) [0xffffff80003934a0] 1-11
latenitefilms commented 4 years ago
CommandPost v1.0.2 (Build: 5686)

Build Date:                     Nov 28 2019, 15:19:38
macOS Version:                  10.14.6
CommandPost Locale:             en_AU
Current Keyboard Layout:        Australian
Final Cut Pro Path:             /Applications/Final Cut Pro.app
Final Cut Pro Version:          10.4.7
Final Cut Pro Language:         en
Developer Mode:                 false

2019-12-01 20:59:42: 2019-12-01 20:59:41: -- Loading /Users/chrishocking/Github/CommandPost-App/build/CommandPost.app/Contents/Resources/extensions/cp/init.lua
2019-12-01 20:59:41: -- Loading extension: hs.uielement
2019-12-01 20:59:42: 20:59:42         cp:     Loading Plugins...
2019-12-01 20:59:49: 20:59:49 ** Warning:   plugins: Slow Plugin: finalcutpro.setup.scan (2.227389)
2019-12-01 20:59:50: 20:59:50         cp:     Plugins Loaded.
2019-12-01 20:59:50:                          Startup Time: 4.409981 seconds
2019-12-01 20:59:50: -- Done.
2019-12-01 21:00:45: ********
2019-12-01 21:00:45: 21:00:45 ERROR:   LuaSkin: hs.timer callback error: .../CommandPost.app/Contents/Resources/extensions/cp/rx.lua:179: Import Next took too long
stack traceback:
    [C]: in function 'error'
    .../CommandPost.app/Contents/Resources/extensions/cp/rx.lua:179: in method 'onError'
    .../CommandPost.app/Contents/Resources/extensions/cp/rx.lua:3005: in function <.../CommandPost.app/Contents/Resources/extensions/cp/rx.lua:2980>
2019-12-01 21:00:45: ********
latenitefilms commented 4 years ago
Command:         CommandPost
Path:            /Users/USER/*/CommandPost.app/Contents/MacOS/CommandPost
Identifier:      org.latenitefilms.CommandPost
Version:         1.0.2 (5686)
Parent:          launchd [1]
PID:             45291

Event:           hang
Duration:        1.50s (process was unresponsive for 6 seconds before sampling)
Steps:           15 (100ms sampling interval)

Hardware model:  MacBookPro14,3
Active cpus:     8

Time Awake Since Boot: 140000s
Time Since Wake: 630s

Fan speed:       2163 rpm

--------------------------------------------------
Timeline format: stacks are sorted chronologically
Use -i and -heavy to re-report with count sorting
--------------------------------------------------

Heaviest stack for the main thread of the target process:
  15  start + 1 (libdyld.dylib + 91093) [0x7fff75c713d5]
  15  NSApplicationMain + 777 (AppKit + 10984) [0x7fff472d1ae8]
  15  -[NSApplication run] + 699 (AppKit + 79272) [0x7fff472e25a8]
  15  -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 1361 (AppKit + 103563) [0x7fff472e848b]
  15  _DPSNextEvent + 1135 (AppKit + 108445) [0x7fff472e979d]
  15  _BlockUntilNextEventMatchingListInModeWithFilter + 64 (HIToolbox + 44150) [0x7fff48f50c76]
  15  ReceiveNextEventCommon + 603 (HIToolbox + 44773) [0x7fff48f50ee5]
  15  RunCurrentEventLoopInMode + 292 (HIToolbox + 45483) [0x7fff48f511ab]
  15  CFRunLoopRunSpecific + 455 (CoreFoundation + 237246) [0x7fff49cf1ebe]
  15  __CFRunLoopRun + 2130 (CoreFoundation + 239970) [0x7fff49cf2962]
  15  __CFRunLoopDoTimers + 330 (CoreFoundation + 366418) [0x7fff49d11752]
  15  __CFRunLoopDoTimer + 851 (CoreFoundation + 367628) [0x7fff49d11c0c]
  15  __CFRUNLOOP_IS_CALLING_OUT_TO_A_TIMER_CALLBACK_FUNCTION__ + 20 (CoreFoundation + 368736) [0x7fff49d12060]
  15  __NSFireTimer + 80 (Foundation + 415739) [0x7fff4bf9f7fb]
  15  -[HSTimer callback:] + 242 (internal.m:51,10 in internal.so + 5255) [0x10c9e0487]
  15  -[LuaSkin protectedCallAndTraceback:nresults:] + 203 (Skin.m:251,9 in LuaSkin + 10776) [0x107b0ca18]
  15  lua_pcallk + 236 (lapi.c:969,14 in LuaSkin + 106016) [0x107b23e20]
  15  luaD_pcall + 110 (ldo.c:156,3 in LuaSkin + 132816) [0x107b2a6d0]
  15  luai_objcttry + 28 (lobjectivec_exceptions.m:84,3 in LuaSkin + 49106) [0x107b15fd2]
  15  luaD_callnoyield + 21 (ldo.c:526,3 in LuaSkin + 131539) [0x107b2a1d3]
  15  luaD_call + 64 (ldo.c:516,5 in LuaSkin + 131474) [0x107b2a192]
  15  luaV_execute + 708 (lvm.c:1134,13 in LuaSkin + 115156) [0x107b261d4]
  15  luaD_precall + 681 (ldo.c:451,11 in LuaSkin + 131108) [0x107b2a024]
  15  luaB_xpcall + 115 (lbaselib.c:441,12 in LuaSkin + 128430) [0x107b295ae]
  15  lua_pcallk + 236 (lapi.c:969,14 in LuaSkin + 106016) [0x107b23e20]
  15  luaD_pcall + 110 (ldo.c:156,3 in LuaSkin + 132816) [0x107b2a6d0]
  15  luai_objcttry + 28 (lobjectivec_exceptions.m:84,3 in LuaSkin + 49106) [0x107b15fd2]
  15  luaD_callnoyield + 21 (ldo.c:526,3 in LuaSkin + 131539) [0x107b2a1d3]
  15  luaD_call + 64 (ldo.c:516,5 in LuaSkin + 131474) [0x107b2a192]
  15  luaV_execute + 708 (lvm.c:1134,13 in LuaSkin + 115156) [0x107b261d4]
  15  luaD_precall + 681 (ldo.c:451,11 in LuaSkin + 131108) [0x107b2a024]
  15  getApplicationElementForPID + 125 (internal.so + 29005) [0x10b0fc14d]
  15  isApplicationOrSystem + 39 (internal.so + 29143) [0x10b0fc1d7]
  15  AXUIElementCopyAttributeValue + 94 (HIServices + 124141) [0x7fff484e34ed]
  15  _AXUIElementCopyAttributeValue + 802 (HIServices + 123716) [0x7fff484e3344]
  15  _AXMIGCopyAttributeValue + 343 (HIServices + 178150) [0x7fff484f07e6]
  15  mach_msg_trap + 10 (libsystem_kernel.dylib + 4650) [0x7fff75da622a]
 *15  hndl_mach_scall64 + 22 (kernel + 1426214) [0xffffff800035c326]
 *15  mach_call_munger64 + 599 (kernel + 2889703) [0xffffff80004c17e7]
 *15  mach_msg_overwrite_trap + 974 (kernel + 1717182) [0xffffff80003a33be]
 *15  ipc_kmsg_send + 469 (kernel + 1633701) [0xffffff800038eda5]
 *15  ipc_mqueue_send + 499 (kernel + 1650099) [0xffffff8000392db3]
 *15  thread_block_reason + 175 (kernel + 1880671) [0xffffff80003cb25f]
 *15  ??? (kernel + 1887161) [0xffffff80003ccbb9]
 *15  machine_switch_context + 195 (kernel + 2976211) [0xffffff80004d69d3]

Process:         CommandPost [45291]
UUID:            7E99A1F7-44E5-34FB-8C50-2EB1EE3BCC14
Path:            /Users/USER/*/CommandPost.app/Contents/MacOS/CommandPost
Architecture:    x86_64
Parent:          launchd [1]
UID:             501
Footprint:       136.40 MB
Start time:      2019-12-01 21:28:38 +1100
End time:        2019-12-01 21:28:39 +1100
Num samples:     15 (1-15)
Note:            Unresponsive for 6 seconds before sampling
Note:            2 idle work queue threads omitted

  Thread 0x39ca7c           DispatchQueue 1           15 samples (1-15)         priority 46 (base 46)
  <thread QoS user interactive (requested user interactive), process unclamped, process received importance donation from WindowServer [214], process received importance donation from pboard [320], IO tier 0>
  15  start + 1 (libdyld.dylib + 91093) [0x7fff75c713d5] 1-15
    15  NSApplicationMain + 777 (AppKit + 10984) [0x7fff472d1ae8] 1-15
      15  -[NSApplication run] + 699 (AppKit + 79272) [0x7fff472e25a8] 1-15
        15  -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 1361 (AppKit + 103563) [0x7fff472e848b] 1-15
          15  _DPSNextEvent + 1135 (AppKit + 108445) [0x7fff472e979d] 1-15
            15  _BlockUntilNextEventMatchingListInModeWithFilter + 64 (HIToolbox + 44150) [0x7fff48f50c76] 1-15
              15  ReceiveNextEventCommon + 603 (HIToolbox + 44773) [0x7fff48f50ee5] 1-15
                15  RunCurrentEventLoopInMode + 292 (HIToolbox + 45483) [0x7fff48f511ab] 1-15
                  15  CFRunLoopRunSpecific + 455 (CoreFoundation + 237246) [0x7fff49cf1ebe] 1-15
                    15  __CFRunLoopRun + 2130 (CoreFoundation + 239970) [0x7fff49cf2962] 1-15
                      15  __CFRunLoopDoTimers + 330 (CoreFoundation + 366418) [0x7fff49d11752] 1-15
                        15  __CFRunLoopDoTimer + 851 (CoreFoundation + 367628) [0x7fff49d11c0c] 1-15
                          15  __CFRUNLOOP_IS_CALLING_OUT_TO_A_TIMER_CALLBACK_FUNCTION__ + 20 (CoreFoundation + 368736) [0x7fff49d12060] 1-15
                            15  __NSFireTimer + 80 (Foundation + 415739) [0x7fff4bf9f7fb] 1-15
                              15  -[HSTimer callback:] + 242 (internal.m:51,10 in internal.so + 5255) [0x10c9e0487] 1-15
                                15  -[LuaSkin protectedCallAndTraceback:nresults:] + 203 (Skin.m:251,9 in LuaSkin + 10776) [0x107b0ca18] 1-15
                                  15  lua_pcallk + 236 (lapi.c:969,14 in LuaSkin + 106016) [0x107b23e20] 1-15
                                    15  luaD_pcall + 110 (ldo.c:156,3 in LuaSkin + 132816) [0x107b2a6d0] 1-15
                                      15  luai_objcttry + 28 (lobjectivec_exceptions.m:84,3 in LuaSkin + 49106) [0x107b15fd2] 1-15
                                        15  luaD_callnoyield + 21 (ldo.c:526,3 in LuaSkin + 131539) [0x107b2a1d3] 1-15
                                          15  luaD_call + 64 (ldo.c:516,5 in LuaSkin + 131474) [0x107b2a192] 1-15
                                            15  luaV_execute + 708 (lvm.c:1134,13 in LuaSkin + 115156) [0x107b261d4] 1-15
                                              15  luaD_precall + 681 (ldo.c:451,11 in LuaSkin + 131108) [0x107b2a024] 1-15
                                                15  luaB_xpcall + 115 (lbaselib.c:441,12 in LuaSkin + 128430) [0x107b295ae] 1-15
                                                  15  lua_pcallk + 236 (lapi.c:969,14 in LuaSkin + 106016) [0x107b23e20] 1-15
                                                    15  luaD_pcall + 110 (ldo.c:156,3 in LuaSkin + 132816) [0x107b2a6d0] 1-15
                                                      15  luai_objcttry + 28 (lobjectivec_exceptions.m:84,3 in LuaSkin + 49106) [0x107b15fd2] 1-15
                                                        15  luaD_callnoyield + 21 (ldo.c:526,3 in LuaSkin + 131539) [0x107b2a1d3] 1-15
                                                          15  luaD_call + 64 (ldo.c:516,5 in LuaSkin + 131474) [0x107b2a192] 1-15
                                                            15  luaV_execute + 708 (lvm.c:1134,13 in LuaSkin + 115156) [0x107b261d4] 1-15
                                                              15  luaD_precall + 681 (ldo.c:451,11 in LuaSkin + 131108) [0x107b2a024] 1-15
                                                                15  getApplicationElementForPID + 125 (internal.so + 29005) [0x10b0fc14d] 1-15
                                                                  15  isApplicationOrSystem + 39 (internal.so + 29143) [0x10b0fc1d7] 1-15
                                                                    15  AXUIElementCopyAttributeValue + 94 (HIServices + 124141) [0x7fff484e34ed] 1-15
                                                                      15  _AXUIElementCopyAttributeValue + 802 (HIServices + 123716) [0x7fff484e3344] 1-15
                                                                        15  _AXMIGCopyAttributeValue + 343 (HIServices + 178150) [0x7fff484f07e6] 1-15
                                                                          15  mach_msg_trap + 10 (libsystem_kernel.dylib + 4650) [0x7fff75da622a] 1-15
                                                                           *15  hndl_mach_scall64 + 22 (kernel + 1426214) [0xffffff800035c326] 1-15
                                                                             *15  mach_call_munger64 + 599 (kernel + 2889703) [0xffffff80004c17e7] 1-15
                                                                               *15  mach_msg_overwrite_trap + 974 (kernel + 1717182) [0xffffff80003a33be] 1-15
                                                                                 *15  ipc_kmsg_send + 469 (kernel + 1633701) [0xffffff800038eda5] 1-15
                                                                                   *15  ipc_mqueue_send + 499 (kernel + 1650099) [0xffffff8000392db3] 1-15
                                                                                     *15  thread_block_reason + 175 (kernel + 1880671) [0xffffff80003cb25f] 1-15
                                                                                       *15  ??? (kernel + 1887161) [0xffffff80003ccbb9] 1-15
                                                                                         *15  machine_switch_context + 195 (kernel + 2976211) [0xffffff80004d69d3] (blocked by mach_msg send owned by Final Cut Pro [45172]) 1-15
latenitefilms commented 4 years ago

Weirdly, the problem seems to be doLaunch() is stalling.

@randomeizer - In the below screenshot, it's stalling at the highlighted section even though it has been activated and frontmost. Any ideas?

Screen Shot 2019-12-02 at 7 07 10 am
latenitefilms commented 4 years ago

Note to self - the rabbit hole continues...

> cp.apple.finalcutpro:timeline():doShow():Now()

2019-12-02 20:20:09: [ERROR: make sure timeline can be enabled]:    Unable to find the menu for Final Cut Pro.
2019-12-02 20:20:09: ********
2019-12-02 20:20:09: 20:20:09 ERROR:   LuaSkin: hs.timer callback error: ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: Unable to find the menu for Final Cut Pro.
stack traceback:
    [C]: in function 'error'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: in method 'onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:2924: in field '_onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: in method 'onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:3024: in field '_onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: in method 'onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:1379: in field '_onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: in method 'onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:1696: in field '_onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: in method 'onError'
    ...
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: in method 'onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:1696: in field '_onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: in method 'onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:3238: in field '_onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: in function <...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:176>
    (...tail calls...)
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: in method 'onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:1818: in field '_onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: in method 'onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:3238: in field '_onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: in field '?'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:1158: in function <...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:1157>
2019-12-02 20:20:09: ********
latenitefilms commented 4 years ago

Note to self...

When it's working:

2019-12-04 23:11:26: [NEXT: Tagging files]: 
2019-12-04 23:11:27: [NEXT: Launching FCPX]:    true
2019-12-04 23:11:27: [NEXT: Showing Timeline]:  true
2019-12-04 23:11:27: [NEXT: Waiting until the timeline is loaded]:  true
2019-12-04 23:11:27: [NEXT: Writing files to the pasteboard]: 
2019-12-04 23:11:27: [COMPLETED: Writing files to the pasteboard]
2019-12-04 23:11:27: [COMPLETED: Waiting until the timeline is loaded]
2019-12-04 23:11:27: [COMPLETED: Showing Timeline]
2019-12-04 23:11:27: [COMPLETED: Launching FCPX]
2019-12-04 23:11:27: [COMPLETED: Tagging files]
2019-12-04 23:11:27: [NEXT: Pasting as connected clip]:     true
2019-12-04 23:11:27: [COMPLETED: Pasting as connected clip]
2019-12-04 23:11:27: 23:11:27    clipmgr:     STARTING PASTEBOARD WATCHER
2019-12-04 23:11:27: [NEXT: Restoring Pasteboard Contents]: 
2019-12-04 23:11:27: [COMPLETED: Restoring Pasteboard Contents]
2019-12-04 23:11:27:                 app:     updating prop because of notification: focusedWindowUI: hs._asm.axuielement: AXWindow (0x600003675918)
2019-12-04 23:11:27:                          updating prop because of notification: hsApplication: hs.application: Final Cut Pro (0x600003447508)
2019-12-04 23:11:27:                          updating prop because of notification: frontmost: true
2019-12-04 23:11:27: [NEXT: Deleting files]:    false
2019-12-04 23:11:27:          MediaFolde:     importingNow is now false, and triggering doImportNext again
2019-12-04 23:11:27: [NEXT: MediaFolder:doImportNext]: 
2019-12-04 23:11:27: [COMPLETED: Deleting files]
2019-12-04 23:11:27: [COMPLETED: MediaFolder:doImportNext]
2019-12-04 23:11:32: 23:11:32        app:     updating prop because of notification: hsApplication: hs.application: Final Cut Pro (0x600003447508)
2019-12-04 23:11:32:                          updating prop because of notification: frontmost: false

When it has a massive delay:

2019-12-04 23:12:55: [NEXT: Tagging files]: 
2019-12-04 23:12:55: [NEXT: Launching FCPX]:    true
2019-12-04 23:12:55: [NEXT: Showing Timeline]:  true
2019-12-04 23:12:55: [NEXT: Waiting until the timeline is loaded]:  true
2019-12-04 23:12:55: [NEXT: Writing files to the pasteboard]: 
2019-12-04 23:12:55: [COMPLETED: Writing files to the pasteboard]
2019-12-04 23:12:55: [COMPLETED: Waiting until the timeline is loaded]
2019-12-04 23:12:55: [COMPLETED: Showing Timeline]
2019-12-04 23:12:55: [COMPLETED: Launching FCPX]
2019-12-04 23:12:55: [COMPLETED: Tagging files]
2019-12-04 23:12:55: [NEXT: Pasting as connected clip]:     true
2019-12-04 23:12:55: [COMPLETED: Pasting as connected clip]
2019-12-04 23:13:55: 23:13:55    clipmgr:     STARTING PASTEBOARD WATCHER
2019-12-04 23:13:55: [NEXT: Restoring Pasteboard Contents]: 
2019-12-04 23:13:55: [COMPLETED: Restoring Pasteboard Contents]
2019-12-04 23:13:56: [ERROR: MediaFolder:doImportNext]:     Import Next took too long
2019-12-04 23:13:56: ********
2019-12-04 23:13:56: 23:13:56 ERROR:   LuaSkin: hs.timer callback error: ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: Import Next took too long
stack traceback:
    [C]: in function 'error'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: in method 'onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:2924: in field '_onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: in method 'onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:3005: in function <...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:2980>
2019-12-04 23:13:56: ********
2019-12-04 23:13:56:                 app:     updating prop because of notification: focusedWindowUI: hs._asm.axuielement: AXWindow (0x60000348d588)
2019-12-04 23:13:56:                          updating prop because of notification: hsApplication: hs.application: Final Cut Pro (0x600003447508)
2019-12-04 23:13:56:                          updating prop because of notification: frontmost: true
2019-12-04 23:13:56: [NEXT: Deleting files]:    false
2019-12-04 23:13:56:          MediaFolde:     importingNow is now false, and triggering doImportNext again
2019-12-04 23:13:56: [COMPLETED: Deleting files]
2019-12-04 23:13:59: 23:13:59        app:     updating prop because of notification: hsApplication: hs.application: Final Cut Pro (0x600003447508)
2019-12-04 23:13:59:                          updating prop because of notification: frontmost: false
latenitefilms commented 4 years ago

Console.app result whilst I have a spinning wheel of doom:

info    23:38:28.482757 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
default 23:38:30.506012 +1100   loginwindow -[PersistentAppsSupport saveLogoutPersistentState:finalSnapshot:] |      previouslyRunningApps: (
        {
        BackgroundState = 0;
        BundleID = "org.latenitefilms.commandpost";
        Hide = 0;
        Path = "/Users/chrishocking/Github/CommandPost-App/build/CommandPost.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.barebones.bbedit";
        Hide = 0;
        Path = "/Applications/BBEdit.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.apple.finder";
        Hide = 0;
        Path = "/System/Library/CoreServices/Finder.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.apple.safari";
        Hide = 0;
        Path = "/Applications/Safari.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.apple.finalcut";
        Hide = 0;
        Path = "/Applications/Final Cut Pro.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.github.github";
        Hide = 0;
        Path = "/Applications/GitHub Desktop.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.apple.activitymonitor";
        Hide = 0;
        Path = "/Applications/Utilities/Activity Monitor.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.apple.mail";
        Hide = 1;
        Path = "/Applications/Mail.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.busymac.busycal3";
        Hide = 1;
        Path = "/Applications/BusyCal.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.apple.quicktimeplayerx";
        Hide = 0;
        Path = "/Applications/QuickTime Player.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.apple.textedit";
        Hide = 0;
        Path = "/Applications/TextEdit.app";
    }
)
info    23:38:30.510276 +1100   loginwindow CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
default 23:38:30.510360 +1100   loginwindow -[PersistentAppsSupport saveLogoutPersistentState:finalSnapshot:] |      checkAgainstApp is : Final Cut Pro
default 23:38:30.510376 +1100   loginwindow -[PersistentAppsSupport appShouldBeRelaunched:] | entered. checking app: Final Cut Pro
default 23:38:30.510405 +1100   loginwindow -[PersistentAppsSupport saveLogoutPersistentState:finalSnapshot:] |           Adding to relaunchArray: Final Cut Pro
debug   23:38:30.532370 +1100   launchservicesd Checking app App:"Final Cut Pro" asn:0x0-1e11e1 pid:15457 refs=6 @ 0x7fa01a016fd0 for keys in { "LSStoppedState"=true }
default 23:38:30.534201 +1100   loginwindow -[PersistentAppsSupport saveLogoutPersistentState:finalSnapshot:] |           Contents:(
        {
        BackgroundState = 2;
        BundleID = "com.apple.console";
        Hide = 0;
        Path = "/Applications/Utilities/Console.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.apple.finalcut";
        Hide = 0;
        Path = "/Applications/Final Cut Pro.app";
    },
        {
        BackgroundState = 2;
        BundleID = "org.latenitefilms.commandpost";
        Hide = 0;
        Path = "/Users/chrishocking/Github/CommandPost-App/build/CommandPost.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.apple.finder";
        Hide = 0;
        Path = "/System/Library/CoreServices/Finder.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.barebones.bbedit";
        Hide = 0;
        Path = "/Applications/BBEdit.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.apple.safari";
        Hide = 0;
        Path = "/Applications/Safari.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.github.github";
        Hide = 0;
        Path = "/Applications/GitHub Desktop.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.apple.activitymonitor";
        Hide = 0;
        Path = "/Applications/Utilities/Activity Monitor.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.apple.mail";
        Hide = 1;
        Path = "/Applications/Mail.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.busymac.busycal3";
        Hide = 1;
        Path = "/Applications/BusyCal.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.apple.quicktimeplayerx";
        Hide = 0;
        Path = "/Applications/QuickTime Player.app";
    },
        {
        BackgroundState = 2;
        BundleID = "com.apple.textedit";
        Hide = 0;
        Path = "/Applications/TextEdit.app";
    }
)
info    23:38:34.484467 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
info    23:38:40.486352 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
info    23:38:46.487066 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
info    23:38:52.488254 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
debug   23:38:54.015429 +1100   Final Cut Pro   EVENT: {affected=3248921U, when=xpc object:<double: 0x600001296be0>: 597155933.995154 , session=100008, clientid=105553155464656U, code=258, id=342U, msgid=772U, info={LSArchitecture="x86_64", DTXcode="1021", CFBundleInfoDictionaryVersion="6.0", ApplicationType="UIElement", DTPlatformBuild="10E1001", CFBundlePackageType="XPC!", NSSupportsAppNap=true, LSBundlePathDeviceID=16777220, Flavor=2, NSPrincipalClass="NSApplication", NSMainNibFile="WebContentProcess", LSExitStatus=0, CFBundleName="com.apple.WebKit.WebContent", pid=25067, CFBundleExecutablePath="/System/Library/StagedFrameworks/Safari/WebKit.framework/Versions/A/XPCServices/com.apple.WebKit.WebContent.xpc/Contents/MacOS/com.apple.WebKit.WebContent", CFBundleIdentifier="com.apple.WebKit.WebContent", CFBundleSignature="????", CFBundleShortVersionString="14608", BuildMachineOSBuild="18A391012", LSDisplayName="Safari Web Content (Cached)", DTSDKName="macosx10.14internal", LSBundlePathLastComponentLowerCaseKey="com.apple.webkit.webcontent.xpc", LSFileQuara<…> from conn <decode: missing data>
debug   23:38:54.016714 +1100   Final Cut Pro   Calling block with kLSNotifyApplicationDeath { "ApplicationType"="UIElement", "BuildMachineOSBuild"="18A391012", "BundleIdentifierLowerCase"="com.apple.webkit.webcontent", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleExecutable"="com.apple.WebKit.WebContent", "CFBundleExecutablePath"="/System/Library/StagedFrameworks/Safari/WebKit.framework/Versions/A/XPCServices/com.apple.WebKit.WebContent.xpc/Contents/MacOS/com.apple.WebKit.WebContent", "CFBundleExecutablePathDeviceID"=16777220, "CFBundleExecutablePathINode"=8702161484, "CFBundleFollowParentLocalization"=true, "CFBundleGetInfoString"="14608.3.10.10.1, Copyright 2003-2019 Apple Inc.", "CFBundleIdentifier"="com.apple.WebKit.WebContent", "CFBundleInfoDictionaryVersion"="6.0", "CFBundleName"="com.apple.WebKit.WebContent", "CFBundleNameLowerCase"="com.apple.webkit.webcontent", "CFBundlePackageType"="XPC!", "CFBundleShortVersionString"="14608", "CFBundleSignature"="????", "CFBundleSupportedPlatforms"=( "MacOSX"), "CFBundleVersion"="14608<…> notificationID=<decode: missing data> id=<decode: missing data>
debug   23:38:54.030026 +1100   Final Cut Pro   EVENT: {affected=2982616U, when=xpc object:<double: 0x600005018820>: 597155934.026192 , session=100008, clientid=105553155464656U, code=258, id=342U, msgid=773U, info={LSArchitecture="x86_64", DTXcode="1021", CFBundleInfoDictionaryVersion="6.0", ApplicationType="UIElement", DTPlatformBuild="10E1001", CFBundlePackageType="XPC!", NSSupportsAppNap=true, LSBundlePathDeviceID=16777220, Flavor=2, NSPrincipalClass="NSApplication", NSMainNibFile="WebContentProcess", LSExitStatus=0, CFBundleName="com.apple.WebKit.WebContent", pid=21674, CFBundleExecutablePath="/System/Library/StagedFrameworks/Safari/WebKit.framework/Versions/A/XPCServices/com.apple.WebKit.WebContent.xpc/Contents/MacOS/com.apple.WebKit.WebContent", CFBundleIdentifier="com.apple.WebKit.WebContent", CFBundleSignature="????", CFBundleShortVersionString="14608", BuildMachineOSBuild="18A391012", LSDisplayName="Safari Web Content (Cached)", DTSDKName="macosx10.14internal", LSBundlePathLastComponentLowerCaseKey="com.apple.webkit.webcontent.xpc", LSFileQuara<…> from conn <decode: missing data>
debug   23:38:54.030762 +1100   Final Cut Pro   Calling block with kLSNotifyApplicationDeath { "ApplicationType"="UIElement", "BuildMachineOSBuild"="18A391012", "BundleIdentifierLowerCase"="com.apple.webkit.webcontent", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleExecutable"="com.apple.WebKit.WebContent", "CFBundleExecutablePath"="/System/Library/StagedFrameworks/Safari/WebKit.framework/Versions/A/XPCServices/com.apple.WebKit.WebContent.xpc/Contents/MacOS/com.apple.WebKit.WebContent", "CFBundleExecutablePathDeviceID"=16777220, "CFBundleExecutablePathINode"=8702161484, "CFBundleFollowParentLocalization"=true, "CFBundleGetInfoString"="14608.3.10.10.1, Copyright 2003-2019 Apple Inc.", "CFBundleIdentifier"="com.apple.WebKit.WebContent", "CFBundleInfoDictionaryVersion"="6.0", "CFBundleName"="com.apple.WebKit.WebContent", "CFBundleNameLowerCase"="com.apple.webkit.webcontent", "CFBundlePackageType"="XPC!", "CFBundleShortVersionString"="14608", "CFBundleSignature"="????", "CFBundleSupportedPlatforms"=( "MacOSX"), "CFBundleVersion"="14608<…> notificationID=<decode: missing data> id=<decode: missing data>
info    23:38:58.489340 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
info    23:39:04.490508 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
info    23:39:10.491956 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
debug   23:39:16.469120 +1100   Final Cut Pro   Finished waiting for promise because timed out
error   23:39:16.469187 +1100   Final Cut Pro   Failed to get a sandbox extension
info    23:39:16.469215 +1100   Final Cut Pro   (not-in-cache) - result: 0 generation: 140 data (63 bytes) flags: 20000000
info    23:39:16.469710 +1100   Final Cut Pro   GetItemCount('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1)
info    23:39:16.469779 +1100   Final Cut Pro   result: 0 gen: 140 count: 3
debug   23:39:16.469857 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.469914 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.470092 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.470256 +1100   Final Cut Pro   notify_check(<private>) == false
info    23:39:16.470355 +1100   Final Cut Pro   GetItemAtIndex('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 idx: 1)
info    23:39:16.470379 +1100   Final Cut Pro   result: 0 gen: 140 item: 789514
info    23:39:16.470402 +1100   Final Cut Pro   CopyFlavorsForItem('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 item: 789514)
info    23:39:16.470421 +1100   Final Cut Pro   result: 0 gen: 140 flavor-count: 1  (-1 means nil)
info    23:39:16.470443 +1100   Final Cut Pro   CopyData('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: 140 item: 789514 flavor: 'public.file-url')
info    23:39:16.470460 +1100   Final Cut Pro   (cache) - result: 0 generation: 140 data (63 bytes) flags: 20000000
debug   23:39:16.470499 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.470605 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.470748 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.470815 +1100   Final Cut Pro   notify_check(<private>) == false
info    23:39:16.470874 +1100   Final Cut Pro   GetItemAtIndex('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 idx: 2)
info    23:39:16.470896 +1100   Final Cut Pro   result: 0 gen: 140 item: 1
info    23:39:16.471011 +1100   Final Cut Pro   CopyFlavorsForItem('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 item: 1)
info    23:39:16.471098 +1100   Final Cut Pro   result: 0 gen: 140 flavor-count: 1  (-1 means nil)
info    23:39:16.471193 +1100   Final Cut Pro   CopyData('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: 140 item: 1 flavor: 'public.file-url')
info    23:39:16.471289 +1100   Final Cut Pro   (cache) - result: 0 generation: 140 data (63 bytes) flags: 20000000
debug   23:39:16.471356 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.471431 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.471581 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.471648 +1100   Final Cut Pro   notify_check(<private>) == false
info    23:39:16.471721 +1100   Final Cut Pro   GetItemAtIndex('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 idx: 3)
info    23:39:16.471812 +1100   Final Cut Pro   result: 0 gen: 140 item: 2
info    23:39:16.471883 +1100   Final Cut Pro   CopyFlavorsForItem('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 item: 2)
info    23:39:16.471907 +1100   Final Cut Pro   result: 0 gen: 140 flavor-count: 1  (-1 means nil)
info    23:39:16.471976 +1100   Final Cut Pro   CopyData('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: 140 item: 2 flavor: 'public.file-url')
info    23:39:16.472054 +1100   Final Cut Pro   (cache) - result: 0 generation: 140 data (63 bytes) flags: 20000000
debug   23:39:16.472594 +1100   Final Cut Pro   Bundle: <private>, key: FFDelete, value: , table: FFLocalizable, localizationName: (null), result: Delete
debug   23:39:16.472835 +1100   Final Cut Pro   Bundle: <private>, key: FFRemoveEffects, value: , table: FFLocalizable, localizationName: (null), result: Remove Effects
debug   23:39:16.473370 +1100   Final Cut Pro   Bundle: <private>, key: FFPasteAppendToEnd, value: , table: FFLocalizable, localizationName: (null), result: Append to Storyline
debug   23:39:16.473674 +1100   Final Cut Pro   Bundle: <private>, key: FFAddNamedEffect, value: , table: FFLocalizable, localizationName: (null), result: Add %@
debug   23:39:16.473733 +1100   Final Cut Pro   looked up value <private> for key FFDefaultVideoTransition in CFPrefsPlistSource<0x600003d7e0d0> (Domain: com.apple.FinalCut, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No) via CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.473812 +1100   Final Cut Pro   Bundle: <private>, key: FFAddNamedEffect, value: , table: FFLocalizable, localizationName: (null), result: Add %@
debug   23:39:16.473845 +1100   Final Cut Pro   looked up value <private> for key FFDefaultVideoEffect in CFPrefsPlistSource<0x600003d7e0d0> (Domain: com.apple.FinalCut, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No) via CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.473919 +1100   Final Cut Pro   Bundle: <private>, key: FFAddNamedEffect, value: , table: FFLocalizable, localizationName: (null), result: Add %@
debug   23:39:16.473949 +1100   Final Cut Pro   looked up value <private> for key FFDefaultAudioEffect in CFPrefsPlistSource<0x600003d7e0d0> (Domain: com.apple.FinalCut, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No) via CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.474032 +1100   Final Cut Pro   Bundle: <private>, key: FFAddFreezeFrame, value: , table: FFLocalizable, localizationName: (null), result: Add Freeze Frame
debug   23:39:16.474350 +1100   Final Cut Pro   found no value for key Ironwood Allowed in CFPrefsManagedSource<0x600037ed4a80> (Domain: com.apple.ironwood.support, User: kCFPreferencesCurrentUser, ByHost: Yes, Container: (null), Contents Need Refresh: No)
debug   23:39:16.474401 +1100   Final Cut Pro   found no value for key Ironwood Allowed in CFPrefsManagedSource<0x600037ed4c40> (Domain: com.apple.ironwood.support, User: kCFPreferencesAnyUser, ByHost: Yes, Container: (null), Contents Need Refresh: No)
debug   23:39:16.474468 +1100   Final Cut Pro   Bundle: <private>, key: Start Dictation…, value: , table: DictationManager, localizationName: (null), result: Start Dictation…
info    23:39:16.474795 +1100   Final Cut Pro   -[SFLGenericList _fetchList] com.apple.LSSharedFileList.RecentApplications
debug   23:39:16.474824 +1100   Final Cut Pro   sending={criteria={CFBundleIdentifier="com.apple.FinalCutPro", }, command=330, }
debug   23:39:16.475471 +1100   Final Cut Pro   Received state for list identifier: com.apple.LSSharedFileList.RecentApplications
info    23:39:16.475513 +1100   Final Cut Pro   com.apple.LSSharedFileList.RecentApplications
debug   23:39:16.475650 +1100   Final Cut Pro   Observers: <private>
debug   23:39:16.478751 +1100   launchservicesd Checking app App:"Final Cut Pro" asn:0x0-1e11e1 pid:15457 refs=6 @ 0x7fa01a016fd0 for keys in { "CFBundleIdentifier"="com.apple.FinalCutPro" }
debug   23:39:16.479905 +1100   Final Cut Pro    reply={success=false, }
debug   23:39:16.479960 +1100   Final Cut Pro   sending={criteria={CFBundleIdentifier="com.apple.FinalCutExpress", }, command=330, }
debug   23:39:16.482657 +1100   launchservicesd Checking app App:"Final Cut Pro" asn:0x0-1e11e1 pid:15457 refs=6 @ 0x7fa01a016fd0 for keys in { "CFBundleIdentifier"="com.apple.FinalCutExpress" }
debug   23:39:16.483776 +1100   Final Cut Pro    reply={success=false, }
debug   23:39:16.484689 +1100   Final Cut Pro   Bundle: <private>, key: CommandSubmenu, value: , table: Commands, localizationName: (null), result: Commands
debug   23:39:16.484982 +1100   Final Cut Pro   Bundle: <private>, key: Undo %@, value: , table: Undo, localizationName: (null), result: Undo %@
debug   23:39:16.485122 +1100   Final Cut Pro   Bundle: <private>, key: Redo, value: , table: Undo, localizationName: (null), result: Redo
info    23:39:16.485383 +1100   Final Cut Pro   GetItemCount('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1)
info    23:39:16.485417 +1100   Final Cut Pro   result: 0 gen: 140 count: 3
debug   23:39:16.485471 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.485521 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.485610 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.485676 +1100   Final Cut Pro   notify_check(<private>) == false
info    23:39:16.485749 +1100   Final Cut Pro   GetItemAtIndex('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 idx: 1)
info    23:39:16.485769 +1100   Final Cut Pro   result: 0 gen: 140 item: 789514
info    23:39:16.485790 +1100   Final Cut Pro   CopyFlavorsForItem('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 item: 789514)
info    23:39:16.485806 +1100   Final Cut Pro   result: 0 gen: 140 flavor-count: 1  (-1 means nil)
info    23:39:16.485824 +1100   Final Cut Pro   CopyData('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: 140 item: 789514 flavor: 'public.file-url')
info    23:39:16.485840 +1100   Final Cut Pro   (cache) - result: 0 generation: 140 data (63 bytes) flags: 20000000
debug   23:39:16.485875 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.485919 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.485992 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.486058 +1100   Final Cut Pro   notify_check(<private>) == false
info    23:39:16.486124 +1100   Final Cut Pro   GetItemAtIndex('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 idx: 2)
info    23:39:16.486146 +1100   Final Cut Pro   result: 0 gen: 140 item: 1
info    23:39:16.486228 +1100   Final Cut Pro   CopyFlavorsForItem('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 item: 1)
info    23:39:16.486305 +1100   Final Cut Pro   result: 0 gen: 140 flavor-count: 1  (-1 means nil)
info    23:39:16.486382 +1100   Final Cut Pro   CopyData('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: 140 item: 1 flavor: 'public.file-url')
info    23:39:16.486448 +1100   Final Cut Pro   (cache) - result: 0 generation: 140 data (63 bytes) flags: 20000000
debug   23:39:16.486534 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.486595 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.486827 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.486916 +1100   Final Cut Pro   notify_check(<private>) == false
info    23:39:16.487033 +1100   Final Cut Pro   GetItemAtIndex('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 idx: 3)
info    23:39:16.487062 +1100   Final Cut Pro   result: 0 gen: 140 item: 2
info    23:39:16.487095 +1100   Final Cut Pro   CopyFlavorsForItem('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 item: 2)
info    23:39:16.487122 +1100   Final Cut Pro   result: 0 gen: 140 flavor-count: 1  (-1 means nil)
info    23:39:16.487154 +1100   Final Cut Pro   CopyData('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: 140 item: 2 flavor: 'public.file-url')
info    23:39:16.487237 +1100   Final Cut Pro   (cache) - result: 0 generation: 140 data (63 bytes) flags: 20000000
info    23:39:16.487604 +1100   Final Cut Pro   GetItemCount('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1)
info    23:39:16.487634 +1100   Final Cut Pro   result: 0 gen: 140 count: 3
debug   23:39:16.487678 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.487721 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.487796 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.487864 +1100   Final Cut Pro   notify_check(<private>) == false
info    23:39:16.487926 +1100   Final Cut Pro   GetItemAtIndex('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 idx: 1)
info    23:39:16.487950 +1100   Final Cut Pro   result: 0 gen: 140 item: 789514
info    23:39:16.487976 +1100   Final Cut Pro   CopyFlavorsForItem('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 item: 789514)
info    23:39:16.487999 +1100   Final Cut Pro   result: 0 gen: 140 flavor-count: 1  (-1 means nil)
info    23:39:16.488026 +1100   Final Cut Pro   CopyData('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: 140 item: 789514 flavor: 'public.file-url')
info    23:39:16.488052 +1100   Final Cut Pro   (cache) - result: 0 generation: 140 data (63 bytes) flags: 20000000
debug   23:39:16.488094 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.488130 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.488265 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.488328 +1100   Final Cut Pro   notify_check(<private>) == false
info    23:39:16.488397 +1100   Final Cut Pro   GetItemAtIndex('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 idx: 2)
info    23:39:16.488423 +1100   Final Cut Pro   result: 0 gen: 140 item: 1
info    23:39:16.488457 +1100   Final Cut Pro   CopyFlavorsForItem('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 item: 1)
info    23:39:16.488519 +1100   Final Cut Pro   result: 0 gen: 140 flavor-count: 1  (-1 means nil)
info    23:39:16.488579 +1100   Final Cut Pro   CopyData('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: 140 item: 1 flavor: 'public.file-url')
info    23:39:16.488627 +1100   Final Cut Pro   (cache) - result: 0 generation: 140 data (63 bytes) flags: 20000000
debug   23:39:16.488671 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.488778 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.488898 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.488996 +1100   Final Cut Pro   notify_check(<private>) == false
info    23:39:16.489065 +1100   Final Cut Pro   GetItemAtIndex('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 idx: 3)
info    23:39:16.489084 +1100   Final Cut Pro   result: 0 gen: 140 item: 2
info    23:39:16.489197 +1100   Final Cut Pro   CopyFlavorsForItem('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: -1 item: 2)
info    23:39:16.489299 +1100   Final Cut Pro   result: 0 gen: 140 flavor-count: 1  (-1 means nil)
info    23:39:16.489366 +1100   Final Cut Pro   CopyData('Apple CFPasteboard general' (<CFUUID 0x600001c009c0> 11723E3A-8989-4D0B-BF79-33B41974E4FB) gen: 140 item: 2 flavor: 'public.file-url')
info    23:39:16.489428 +1100   Final Cut Pro   (cache) - result: 0 generation: 140 data (63 bytes) flags: 20000000
debug   23:39:16.489762 +1100   Final Cut Pro   Bundle: <private>, key: FFDelete, value: , table: FFLocalizable, localizationName: (null), result: Delete
debug   23:39:16.490114 +1100   Final Cut Pro   Bundle: <private>, key: FFRemoveEffects, value: , table: FFLocalizable, localizationName: (null), result: Remove Effects
debug   23:39:16.490911 +1100   Final Cut Pro   Bundle: <private>, key: FFPasteAppendToEnd, value: , table: FFLocalizable, localizationName: (null), result: Append to Storyline
debug   23:39:16.491343 +1100   Final Cut Pro   Bundle: <private>, key: FFAddNamedEffect, value: , table: FFLocalizable, localizationName: (null), result: Add %@
debug   23:39:16.491414 +1100   Final Cut Pro   looked up value <private> for key FFDefaultVideoTransition in CFPrefsPlistSource<0x600003d7e0d0> (Domain: com.apple.FinalCut, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No) via CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.491523 +1100   Final Cut Pro   Bundle: <private>, key: FFAddNamedEffect, value: , table: FFLocalizable, localizationName: (null), result: Add %@
debug   23:39:16.491571 +1100   Final Cut Pro   looked up value <private> for key FFDefaultVideoEffect in CFPrefsPlistSource<0x600003d7e0d0> (Domain: com.apple.FinalCut, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No) via CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.491681 +1100   Final Cut Pro   Bundle: <private>, key: FFAddNamedEffect, value: , table: FFLocalizable, localizationName: (null), result: Add %@
debug   23:39:16.491727 +1100   Final Cut Pro   looked up value <private> for key FFDefaultAudioEffect in CFPrefsPlistSource<0x600003d7e0d0> (Domain: com.apple.FinalCut, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No) via CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.491836 +1100   Final Cut Pro   Bundle: <private>, key: FFAddFreezeFrame, value: , table: FFLocalizable, localizationName: (null), result: Add Freeze Frame
debug   23:39:16.492189 +1100   Final Cut Pro   found no value for key Ironwood Allowed in CFPrefsManagedSource<0x600037ed4a80> (Domain: com.apple.ironwood.support, User: kCFPreferencesCurrentUser, ByHost: Yes, Container: (null), Contents Need Refresh: No)
debug   23:39:16.492233 +1100   Final Cut Pro   found no value for key Ironwood Allowed in CFPrefsManagedSource<0x600037ed4c40> (Domain: com.apple.ironwood.support, User: kCFPreferencesAnyUser, ByHost: Yes, Container: (null), Contents Need Refresh: No)
debug   23:39:16.492295 +1100   Final Cut Pro   Bundle: <private>, key: Start Dictation…, value: , table: DictationManager, localizationName: (null), result: Start Dictation…
info    23:39:16.501975 +1100   Final Cut Pro   CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 573 was still valid, so using cached info { "ApplicationType"="UIElement", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.spotlight", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="en", "CFBundleDisplayName"="Spotlight", "CFBundleExecutable"="Spotlight", "CFBundleExecutablePath"="/System/Library/CoreServices/Spotlight.app/Contents/MacOS/Spotlight", "CFBundleExecutablePathDeviceID"=16777220, "CFBundleExecutablePathINode"=8676762219, "CFBundleIconFile"="AppIcon", "CFBundleIconName"="AppIcon", "CFBundleIdentifier"="com.apple.Spotlight", "CFBundleInfoDictionaryVersion"="6.0", "CFBundleName"="Spotlight", "CFBundleNameLowerCase"="spotlight", "CFBundleNumericVersion"=0, "CFBundlePackageType"="APPL", "CFBundleShortVersionString"="1.0", "CFBundleSignature"="????", "CFBundleSupportedPlatforms"=( "MacOSX"), "CFBundleVersion"="1191.57", "ChangeCount"=573, "DTCompiler"="com.apple.compilers.llvm.clang.1_0", "DT<…>
debug   23:39:16.502032 +1100   Final Cut Pro   CopyFrontApplication() = <private>
debug   23:39:16.511254 +1100   Final Cut Pro   found no value for key NSAutomaticWindowAnimationsEnabled in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.511460 +1100   Final Cut Pro   found no value for key ApplePersistenceIgnoreState in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.511494 +1100   Final Cut Pro   found no value for key ApplePersistenceIgnoreStateQuietly in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.511567 +1100   Final Cut Pro    result="Foreground" for keyRef="ApplicationType" ASN=ASN:0x0-0x2: sessionID=100008
debug   23:39:16.511598 +1100   Final Cut Pro    result="Foreground" for keyRef="ApplicationType" ASN=ASN:0x0-0x2: sessionID=100008
debug   23:39:16.511623 +1100   Final Cut Pro    result="Foreground" for keyRef="ApplicationType" ASN=ASN:0x0-0x2: sessionID=100008
debug   23:39:16.511844 +1100   Final Cut Pro   looked up value <private> for key FFHardwarePlaybackDeviceUID in CFPrefsPlistSource<0x600003d7e0d0> (Domain: com.apple.FinalCut, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No) via CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.518264 +1100   Final Cut Pro   Bundle: <private>, key: PEDefaultLibraryName, value: , table: PELocalizable, localizationName: (null), result: Untitled
debug   23:39:16.518323 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.525638 +1100   Final Cut Pro   looked up value <private> for key FFOverrideConnectionsKey in CFPrefsPlistSource<0x600003d7e0d0> (Domain: com.apple.FinalCut, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No) via CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.525731 +1100   Final Cut Pro   looked up value <private> for key FFHardwarePlaybackDeviceUID in CFPrefsPlistSource<0x600003d7e0d0> (Domain: com.apple.FinalCut, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No) via CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.526821 +1100   launchservicesd MESSAGE: reply={result={LSApplicationHasSignalledItIsReady=true, ApplicationType="Foreground", ChangeCount=548, pid=15457, Hidden=false, LSDisplayName="Final Cut Pro", }, success=true, cacheable=false, } (for client 558)
debug   23:39:16.526888 +1100   LogiMgrDaemon    reply={result={ApplicationType="Foreground", LSApplicationHasSignalledItIsReady=true, ChangeCount=548, pid=15457, Hidden=false, LSDisplayName="Final Cut Pro", }, success=true, cacheable=false, }
debug   23:39:16.559701 +1100   LogiMgrDaemon    reply={result={CFBundleExecutablePath="/Applications/Final Cut Pro.app/Contents/MacOS/Final Cut Pro", }, success=true, cacheable=false, }
debug   23:39:16.559781 +1100   launchservicesd MESSAGE: reply={result={CFBundleExecutablePath="/Applications/Final Cut Pro.app/Contents/MacOS/Final Cut Pro", }, success=true, cacheable=false, } (for client 558)
debug   23:39:16.563768 +1100   Final Cut Pro   Bundle: <private>, key: PEDefaultLibraryName, value: , table: PELocalizable, localizationName: (null), result: Untitled
debug   23:39:16.563848 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.567791 +1100   Final Cut Pro   found no value for key bristol in CFPrefsSearchListSource<0x60000386d680> (Domain: com.apple.universalaccess, Container: (null))
debug   23:39:16.579884 +1100   Final Cut Pro   looked up value <private> for key com.fxfactory.TimecodePlugIn.windowHidden in CFPrefsPlistSource<0x600003d7e0d0> (Domain: com.apple.FinalCut, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No) via CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.606955 +1100   Final Cut Pro   found no value for key PAPerfLoggingDisableLiveToggle in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.607010 +1100   Final Cut Pro   found no value for key NSAnimationLogPerformance in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.607043 +1100   Final Cut Pro   found no value for key PAPerfLoggingEnableLogging in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.607088 +1100   Final Cut Pro   found no value for key PAPerfLoggingDisableLiveToggle in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.607117 +1100   Final Cut Pro   found no value for key NSAnimationLogPerformance in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.607146 +1100   Final Cut Pro   found no value for key PAPerfLoggingEnableLogging in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.607181 +1100   Final Cut Pro   found no value for key PAPerfLoggingDisableOperationTimeout in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.607228 +1100   Final Cut Pro   found no value for key PAPerfLoggingDisableLiveToggle in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.607259 +1100   Final Cut Pro   found no value for key NSAnimationLogPerformance in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.607288 +1100   Final Cut Pro   found no value for key PAPerfLoggingEnableLogging in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.609551 +1100   Final Cut Pro   looked up value <private> for key FFHardwarePlaybackDeviceUID in CFPrefsPlistSource<0x600003d7e0d0> (Domain: com.apple.FinalCut, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No) via CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.609874 +1100   Final Cut Pro   found no value for key NSAutomaticWindowAnimationsEnabled in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.609925 +1100   Final Cut Pro   found no value for key ApplePersistenceIgnoreState in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.609963 +1100   Final Cut Pro   found no value for key ApplePersistenceIgnoreStateQuietly in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.613273 +1100   Final Cut Pro   Bundle: <private>, key: PEDefaultLibraryName, value: , table: PELocalizable, localizationName: (null), result: Untitled
debug   23:39:16.613335 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.621153 +1100   Final Cut Pro   found no value for key NSPersistentUIShowQuietSafeQuitStatus in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.666058 +1100   Final Cut Pro   Bundle: <private>, key: PEDefaultLibraryName, value: , table: PELocalizable, localizationName: (null), result: Untitled
debug   23:39:16.666126 +1100   Final Cut Pro   notify_check(<private>) == false
debug   23:39:16.668878 +1100   Final Cut Pro   found no value for key bristol in CFPrefsSearchListSource<0x60000386d680> (Domain: com.apple.universalaccess, Container: (null))
debug   23:39:16.679208 +1100   Final Cut Pro   looked up value <private> for key com.fxfactory.TimecodePlugIn.windowHidden in CFPrefsPlistSource<0x600003d7e0d0> (Domain: com.apple.FinalCut, User: kCFPreferencesCurrentUser, ByHost: No, Container: (null), Contents Need Refresh: No) via CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
debug   23:39:16.728505 +1100   Final Cut Pro   found no value for key NSPersistentUIShowQuietSafeQuitStatus in CFPrefsSearchListSource<0x60000398a900> (Domain: com.apple.FinalCut, Container: (null))
info    23:39:16.762917 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
info    23:39:16.763714 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
debug   23:39:17.171781 +1100   launchservicesd Checking app App:"Final Cut Pro" asn:0x0-1e11e1 pid:15457 refs=6 @ 0x7fa01a016fd0 for keys in { "BundleIdentifierLowerCase"="org.latenitefilms.commandpost" }
debug   23:39:17.236600 +1100   launchservicesd MESSAGE: reply={result={LSApplicationHasSignalledItIsReady=true, ApplicationType="Foreground", ChangeCount=548, pid=15457, Hidden=false, LSDisplayName="Final Cut Pro", }, success=true, cacheable=false, } (for client 558)
debug   23:39:17.236640 +1100   LogiMgrDaemon    reply={result={ApplicationType="Foreground", LSApplicationHasSignalledItIsReady=true, ChangeCount=548, pid=15457, Hidden=false, LSDisplayName="Final Cut Pro", }, success=true, cacheable=false, }
info    23:39:17.324847 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
info    23:39:17.388656 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
info    23:39:17.389133 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
info    23:39:17.390348 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
info    23:39:17.487814 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
info    23:39:17.488551 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
info    23:39:17.489825 +1100   CommandPost CFDictionaryRef FindApplicationInformationDictionaryGivenASNUsingLocalCache(LSSessionID, LSASNRef)(), information in shared memory with seed 548 was still valid, so using cached info { "ApplicationType"="Foreground", "ATSApplicationFontsPath"="Fonts/", "BuildMachineOSBuild"="17A405001", "BundleIdentifierLowerCase"="com.apple.finalcut", "CanBecomeFrontmost"=true, "CFBundleDevelopmentRegion"="English", "CFBundleDocumentTypes"=( { "CFBundleTypeExtensions"=( "cboard"), "CFBundleTypeIconFile"="Icon_Vertigo_ColorPreset.icns", "CFBundleTypeName"="Color Preset", "CFBundleTypeOSTypes"=( "*"), "CFBundleTypeRole"="Viewer", "LSTypeIsPackage"=false, "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpproject"), "CFBundleTypeIconFile"="Icon_Vertigo_Project.icns", "CFBundleTypeName"="Final Cut Pro Project", "CFBundleTypeRole"="None", "LSItemContentTypes"=( "com.apple.FinalCutProProject"), "LSTypeIsPackage"=false, "NSDocumentClass"="FFSequenceDocument", "NSPersistentStoreTypeKey"="Binary" }, { "CFBundleTypeExtensions"=( "fcpevent"), "CFBundleTypeIconFile"="Icon_Verti<…>
debug   23:39:21.306600 +1100   LogiMgrDaemon    reply={result={ApplicationType="Foreground", LSApplicationHasSignalledItIsReady=true, ChangeCount=548, pid=15457, Hidden=false, LSDisplayName="Final Cut Pro", }, success=true, cacheable=false, }
debug   23:39:21.306830 +1100   launchservicesd MESSAGE: reply={result={LSApplicationHasSignalledItIsReady=true, ApplicationType="Foreground", ChangeCount=548, pid=15457, Hidden=false, LSDisplayName="Final Cut Pro", }, success=true, cacheable=false, } (for client 558)
latenitefilms commented 4 years ago

Debugging:

2019-12-05 00:45:44: 00:45:44   notifier:     notification: AXFocusedWindowChanged; ui: hs._asm.axuielement: AXWindow (0x60000369baa8); details: {}
2019-12-05 00:45:44:                          notification: AXMainWindowChanged; ui: hs._asm.axuielement: AXWindow (0x6000036d5018); details: {}
2019-12-05 00:45:44:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXMenuButton (0x6000036d6de8); details: {}
2019-12-05 00:45:44:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXMenuButton (0x6000036d5ee8); details: {}
2019-12-05 00:45:44:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXMenuButton (0x6000036d4508); details: {}
2019-12-05 00:45:44:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXStaticText (0x6000036d5648); details: {}
2019-12-05 00:45:44:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXStaticText (0x600003555dc8); details: {}
2019-12-05 00:45:44:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXStaticText (0x600003555fd8); details: {}
2019-12-05 00:45:44:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXStaticText (0x600003554868); details: {}
2019-12-05 00:45:44:                          notification: AXApplicationActivated; ui: hs._asm.axuielement: AXApplication (0x600003557a78); details: {}
2019-12-05 00:47:14: 00:47:14        app:     updating prop because of notification: 189: focusedWindowUI: hs._asm.axuielement: AXWindow (0x6000036d1a08)
2019-12-05 00:47:14:                          updating prop because of notification: 8: hsApplication: hs.application: Final Cut Pro (0x60000340eb18)
2019-12-05 00:47:14:                          updating prop because of notification: 48: frontmost: true
2019-12-05 00:47:14: ********
2019-12-05 00:47:14: 00:47:14 ERROR:   LuaSkin: hs.timer callback error: ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: Import Next took too long
stack traceback:
    [C]: in function 'error'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:179: in method 'onError'
    ...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:3005: in function <...chrishocking/Github/CommandPost/src/extensions/cp/rx.lua:2980>
2019-12-05 00:47:14: ********
2019-12-05 00:47:14:            notifier:     notification: AXValueChanged; ui: hs._asm.axuielement: AXStaticText (0x6000036d3f88); details: {}
2019-12-05 00:47:14:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXStaticText (0x6000036d16a8); details: {}
2019-12-05 00:47:14:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXStaticText (0x6000036d29c8); details: {}
2019-12-05 00:47:14:                          notification: AXMenuItemSelected; ui: hs._asm.axuielement: AXMenuItem (0x6000036d0718); details: {}
2019-12-05 00:47:14:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXProgressIndicator (0x6000036d05c8); details: {}
2019-12-05 00:47:14:                          notification: AXSelectedChildrenChanged; ui: hs._asm.axuielement: AXGroup (0x6000036d11f8); details: {}
2019-12-05 00:47:16: 00:47:16                 notification: AXValueChanged; ui: hs._asm.axuielement: AXProgressIndicator (0x60000343cf88); details: {}
2019-12-05 00:47:16:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXProgressIndicator (0x60000343e788); details: {}
2019-12-05 00:47:16:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXProgressIndicator (0x6000036f2ed8); details: {}
2019-12-05 00:47:16:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXProgressIndicator (0x6000036f20f8); details: {}
2019-12-05 00:47:16:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXProgressIndicator (0x6000036f1ac8); details: {}
2019-12-05 00:47:16:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXProgressIndicator (0x6000036f2038); details: {}
2019-12-05 00:47:16:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXProgressIndicator (0x6000036f02c8); details: {}
2019-12-05 00:47:16:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXProgressIndicator (0x6000036f1fd8); details: {}
2019-12-05 00:47:16:                          notification: AXValueChanged; ui: hs._asm.axuielement: AXProgressIndicator (0x6000036f04d8); details: {}
2019-12-05 00:47:17: 00:47:17                 notification: AXApplicationDeactivated; ui: hs._asm.axuielement: AXApplication (0x6000034adcd8); details: {}
2019-12-05 00:47:17:                 app:     updating prop because of notification: 8: hsApplication: hs.application: Final Cut Pro (0x60000340eb18)
2019-12-05 00:47:17:                          updating prop because of notification: 48: frontmost: false
latenitefilms commented 4 years ago

A look at what happens with all the prop notifications when you trigger doLaunch():

https://gist.github.com/latenitefilms/30464b1c2882f0b0aedb3900d98a9d6f

latenitefilms commented 4 years ago

Removing the Rx-ified code, and replacing it with this removes the delay:

--- plugins.finalcutpro.watchfolders.media.MediaFolder:doImportNext() -> nil
--- Method
--- Imports the next file in the Media Folder.
---
--- Parameters:
---  * None
---
--- Returns:
---  * None
function MediaFolder.mt:doImportNext()
    local timeline = fcp:timeline()
    local context = {}

    return Do(function()
        if self.importingNow ~= true and #self.importing > 0 then

            self.importingNow = true
            local files = self.importing:popLeft()
            self:save()

            fcp:launch()

            local objects = {}
            for _, v in pairs(files) do
                objects[#objects + 1] = { url = "file://" .. http.encodeForQuery(v) }
            end
            pasteboard.writeObjects(objects)

            fcp:doShortcut("PasteAsConnected"):Now()

            self.importingNow = false
            return self:doImportNext()
        else
            self.importingNow = false
            self:updateReadyNotification()
        end
    end)
end
latenitefilms commented 4 years ago

This also works, but is a little bit slower it seems:

function MediaFolder.mt:doImportNext()
    local timeline = fcp:timeline()
    local context = {}

    return If(function() return self.importingNow ~= true and #self.importing > 0 end):Then(function()
        self.importingNow = true
        local files = self.importing:popLeft()
        self:save()

        return Do(function()

            fcp:launch()

            local objects = {}
            for _, v in pairs(files) do
                objects[#objects + 1] = { url = "file://" .. http.encodeForQuery(v) }
            end
            pasteboard.writeObjects(objects)

            fcp:doShortcut("PasteAsConnected"):Now()

            self.importingNow = false
            return self:doImportNext()
        end)
    end)
    :Otherwise(function()
        self.importingNow = false
        self:updateReadyNotification()
    end)

    :Label("MediaFolder:doImportNext")
end
latenitefilms commented 4 years ago

This also works:

function MediaFolder.mt:doImportNext()
    local timeline = fcp:timeline()
    local context = {}

    return If(function() return self.importingNow ~= true and #self.importing > 0 end):Then(function()
        self.importingNow = true
        local files = self.importing:popLeft()
        self:save()

        return Do(fcp:doLaunch())

        :Then(function()

            local objects = {}
            for _, v in pairs(files) do
                objects[#objects + 1] = { url = "file://" .. http.encodeForQuery(v) }
            end
            pasteboard.writeObjects(objects)

            fcp:doShortcut("PasteAsConnected"):Now()

            self.importingNow = false
            return self:doImportNext()
        end)
    end)
    :Otherwise(function()
        self.importingNow = false
        self:updateReadyNotification()
    end)

    :Label("MediaFolder:doImportNext")
end
latenitefilms commented 4 years ago

This also works:

function MediaFolder.mt:doImportNext()
    local timeline = fcp:timeline()
    local context = {}

    return If(function() return self.importingNow ~= true and #self.importing > 0 end):Then(function()
        self.importingNow = true
        local files = self.importing:popLeft()
        self:save()

        return Do(fcp:doLaunch())

        :Then(function()

            local objects = {}
            for _, v in pairs(files) do
                objects[#objects + 1] = { url = "file://" .. http.encodeForQuery(v) }
            end
            pasteboard.writeObjects(objects)
        end)

        :Then(fcp:doShortcut("PasteAsConnected"))

        :Then(function()
            self.importingNow = false
            return self:doImportNext()
        end)
    end)
    :Otherwise(function()
        self.importingNow = false
        self:updateReadyNotification()
    end)

    :Label("MediaFolder:doImportNext")
end
latenitefilms commented 4 years ago

This is also working - I'm getting very confused as to what exactly was causing the freeze!

--- plugins.finalcutpro.watchfolders.media.MediaFolder:doImportNext() -> nil
--- Method
--- Imports the next file in the Media Folder.
---
--- Parameters:
---  * None
---
--- Returns:
---  * None
function MediaFolder.mt:doImportNext()
    local timeline = fcp:timeline()
    local context = {}

    return If(function() return self.importingNow ~= true and #self.importing > 0 end):Then(function()
        self.importingNow = true
        local files = self.importing:popLeft()
        self:save()

        --------------------------------------------------------------------------------
        -- Tag the files:
        --------------------------------------------------------------------------------
        return Do(self:doTagFiles(files))

        --------------------------------------------------------------------------------
        -- Make sure Final Cut Pro is Active:
        --------------------------------------------------------------------------------
        :Then(fcp:doLaunch())

        --------------------------------------------------------------------------------
        -- Check if Timeline can be enabled:
        --------------------------------------------------------------------------------
        :Then(
            timeline:doShow()
            :TimeoutAfter(1000, i18n("fcpMediaFolder_Error_ShowTimeline"))
        )

        :Then(
            WaitUntil(timeline.isLoaded)
            :TimeoutAfter(1000, i18n("fcpMediaFolder_Error_ProjectRequired"))
        )

        --------------------------------------------------------------------------------
        -- Put the media onto the pasteboard:
        --------------------------------------------------------------------------------
        --:Then(self:doWriteFilesToPasteboard(files, context))

        :Then(function()

            if files == nil or #files == 0 then
                return Throw(i18n("fcpMediaFolder_Error_NoFiles"))
            end
            --------------------------------------------------------------------------------
            -- Temporarily stop the Pasteboard Watcher:
            --------------------------------------------------------------------------------
            if self.mod.pasteboardManager then
                self.mod.pasteboardManager.stopWatching()
            end

            --------------------------------------------------------------------------------
            -- Save current Pasteboard Content:
            --------------------------------------------------------------------------------
            --context.originalPasteboard = pasteboard.readAllData()

            --------------------------------------------------------------------------------
            -- Write URL to Pasteboard:
            --------------------------------------------------------------------------------
            local objects = {}
            for _, v in pairs(files) do
                objects[#objects + 1] = { url = "file://" .. http.encodeForQuery(v) }
            end
            local result = pasteboard.writeObjects(objects)
            if not result then
                return Throw(i18n("fcpMediaFolder_Error_UnableToPaste", {file = files[1], count = #files}))
            end

        end)

        --------------------------------------------------------------------------------
        -- Perform Paste:
        --------------------------------------------------------------------------------
        -- TODO: Figure out bug where FCP menus are not working correctly after writing to the pasteboard
        -- :Then(
        --     fcp:doSelectMenu({"Edit", "Paste as Connected Clip"})
        --     :TimeoutAfter(10000, "Timed out while pasting.")
        -- )
        :Then(fcp:doShortcut("PasteAsConnected"))

        --------------------------------------------------------------------------------
        -- Remove from Timeline if appropriate:
        --------------------------------------------------------------------------------
        :Then(
            If(self.mod.insertIntoTimeline):Is(false):Then(
                fcp:doShortcut("UndoChanges")
            )
        )

        --------------------------------------------------------------------------------
        -- Restore original Pasteboard Content:
        --------------------------------------------------------------------------------
        --:Then(self:doRestoreOriginalPasteboard(context))

        --------------------------------------------------------------------------------
        -- Delete the imported files (if configured):
        --------------------------------------------------------------------------------
        :Then(self:doDeleteImportedFiles(files))

        --------------------------------------------------------------------------------
        -- Try importing the next set of files in the queue:
        --------------------------------------------------------------------------------
        :Then(function()
            self.importingNow = false
            return self:doImportNext()
        end)
        :Catch(function(message)
            self.importingNow = false
            log.ef("Error during `doImportNext`: %s", message)
            dialog.displayMessage(message)
            return self:doImportNext()
        end)
    end)
    :Otherwise(function()
        self.importingNow = false
        self:updateReadyNotification()
    end)
    :Label("MediaFolder:doImportNext")
end
CopaceticMeatbag commented 3 years ago

I'm running into this issue again, even with the new code. Sometimes the file import/place on timeline works instantly, but I can very reliably induce a rainbow wheel by just trying to import more files. Seems to be freezing on two parts; the "doLaunch" to confirm FCP is active (which I've commented out now with seemingly no negative impact) and on the "PasteasConnected" command. My weak guess would be that it's the system clipboard manager inducing the delay (at least it's very similar to an issue I hit using Windows clipboard, had to define a 2nd clipboard and use that instead to solve my issues).

latenitefilms commented 3 years ago

Thanks for reporting @CopaceticMeatbag! We'll do some digging and see what we can come up with.

randomeizer commented 3 years ago

Without actually testing, my first guess is it is some disconnect between waiting for FCP to be 'active' vs receiving a notification from the OS that it is actually active. I wonder if we would get more useful error logs now?

CopaceticMeatbag commented 3 years ago

Not an entire fix, but adding CommandPost to the Full Disk Access list in Security & Privacy has significantly improved my success rates & reduced delay times when they happen.

latenitefilms commented 3 years ago

Huh, that's very strange.

CopaceticMeatbag commented 2 years ago

Little update, in the end I had to workaround this issue by using an applescript instead of hs.pasteboad. I setup a watch folder using Folder Actions, then use the POSIX Path to save a POSIX File link to the clipboard and the Option-V PasteAsConnected shortcut to insert. Works 100% of the time with no spinning ball! I can only surmise that the issue must be related to hammerspoon/pasteboard.