00000001 0.00000000 [8832] MM5 [10392](R) **** focusControl: MainToolbar 00000002 0.13683777 [8832] MM5 [10392](R) BQ: Currently running 1 threads of 10 00000003 0.13804199 [8832] MM5 [10104](R) BQ: Thread[10104] is executing new task now: Callstack: Script: file:///UpdateLocationOfFiles/init.js ; Func: eval ; Row: 3 ; Col: 26 00000004 0.13839620 [8832] MM5 [10104](R) RenameFile: Moving j:\Music\Rock\05 - Shock the Monkey.ogg -> j:\Temp\05 - Shock the Monkey.ogg 00000005 0.14114861 [8832] MM5 [10104](R) PrepareForTagging: called 00000006 0.14162995 [8832] MM5 [10104](R) RestoreFromTagging starting. 00000007 0.14170253 [8832] MM5 [10104](R) RestoreFromTagging finished. 00000008 0.14178476 [8832] MM5 [10104](R) RenameFile: Success 00000009 0.14475556 [8832] MM5 [10104](R) BQ: Thread[10104] is executing new task now: Callstack: Script: file:///UpdateLocationOfFiles/init.js ; Func: eval ; Row: 4 ; Col: 18 00000010 0.14679983 [8832] MM5 [10104](R) DB exec SQL: UPDATE Songs SET SongPath = ':\Temp\Test.mp3' WHERE ID = 1 00000011 0.32960069 [8832] MM5 [10104](R) DB lock took 172 ms : UPDATE Songs SET SongPath = ':\Temp\Test.mp3' WHERE ID = 1 00000012 0.33109167 [8832] MM5 [10104](R) BQ: Thread[10104] is executing new task now: Callstack: Script: file:///UpdateLocationOfFiles/init.js ; Func: eval ; Row: 5 ; Col: 18 00000013 0.33476156 [8832] MM5 [10104](R) BQ: Thread[10104] is executing new task now: Callstack: Script: file:///viewHandlers.js ; Func: onHide ; Row: 289 ; Col: 96 00000014 0.33476156 [8832] Script: file:///viewHandlers.js ; Func: onHide ; Row: 326 ; Col: 56 00000015 0.33476156 [8832] Script: file:///controls/multiview.js ; Func: _process ; Row: 1175 ; Col: 38 00000016 0.33476156 [8832] Script: file:///controls/multiview.js ; Func: _handler_call_onHide ; Row: 1183 ; Col: 13 00000017 0.33476156 [8832] Script: file:///controls/multiview.js ; Func: reload ; Row: 1194 ; Col: 14 00000018 0.33893627 [8832] MM5 [10104](R) BQ: Thread[10104] is executing new task now: Callstack: Script: file:///viewHandlers.js ; Func: __refreshTracklist ; Row: 196 ; Col: 57 00000019 0.33893627 [8832] Script: file:///viewHandlers.js ; Func: onShow ; Row: 238 ; Col: 13 00000020 0.33893627 [8832] Script: file:///viewHandlers.js ; Func: onShow ; Row: 323 ; Col: 56 00000021 0.33893627 [8832] Script: file:///controls/multiview.js ; Func: _process ; Row: 1134 ; Col: 38 00000022 0.33893627 [8832] Script: file:///controls/multiview.js ; Func: _handler_call_onShow ; Row: 1140 ; Col: 13 00000023 0.33967483 [8832] MM5 [10104](R) DB open SQL: SELECT Songs.* FROM Songs 00000024 0.34000313 [8832] MM5 [10104](R) ***** StandardSongQueryCopy starting 00000025 0.34029078 [8832] MM5 [10104](R) ***** StandardSongQueryCopy main loop finishing... was terminated: false 00000026 0.34037030 [8832] MM5 [10104](R) ***** StandardSongQueryCopy adding 2 00000027 0.34049863 [8832] MM5 [10104](R) ***** total tracklist loading time 0ms for 2 00000028 0.34935677 [8832] MM5 [10104](R) BQ: Thread[10104] is executing new task now: Callstack: Script: file:///UpdateLocationOfFiles/init.js ; Func: eval ; Row: 7 ; Col: 26 00000029 0.34945226 [8832] MM5 [10104](R) hasFolderUsefulContent: FALSE, path: j:\Music\Rock\ 00000030 0.34947938 [8832] MM5 [10104](R) Removing folder: j:\Music\Rock\ 00000031 0.34949896 [8832] MM5 [10392](R) BQ: Currently running 2 threads of 10 00000032 0.35032606 [8832] MM5 [10104](R) PrepareFolderDeletion: PlayerLock locked 00000033 0.35071793 [8832] MM5 [10104](R) PrepareFolderDeletion: PlayerLock unlocked 00000034 0.35138419 [8832] MM5 [9892](R) BQ: Thread[9892] is executing new task now: Callstack: Script: file:///controls/listview.js ; Func: eval ; Row: 3494 ; Col: 37 00000035 0.35138419 [8832] Script: file:///promise.js ; Func: invokeResolver ; Row: 387 ; Col: 18 00000036 0.35138419 [8832] Script: file:///promise.js ; Func: Promise ; Row: 374 ; Col: 7 00000037 0.35138419 [8832] Script: file:///controls/listview.js ; Func: setDataSourceSameView ; Row: 3493 ; Col: 38 00000038 0.35138419 [8832] Script: file:///viewHandlers.js ; Func: _assign ; Row: 207 ; Col: 50 00000039 0.37834632 [8832] MM5 [9892](R) BQ: Thread[9892] is executing new task now: Callstack: Script: file:///controls/trackListView.js ; Func: handle_datasourcechanged ; Row: 2081 ; Col: 20 00000040 0.37834632 [8832] Script: file:///controls/listview.js ; Func: set ; Row: 3733 ; Col: 28 00000041 0.37834632 [8832] Script: file:///controls/listview.js ; Func: eval ; Row: 3498 ; Col: 37 00000042 0.40875486 [8832] MM5 [9892](R) BQ: Thread[9892] is executing new task now: Callstack: Script: file:///controls/control.js ; Func: eval ; Row: 1207 ; Col: 29 00000043 0.40875486 [8832] Script: file:///controls/control.js ; Func: eval ; Row: 282 ; Col: 13 00000044 0.44843748 [8832] MM5 [9892](R) BQ: Thread[9892] is executing new task now: TSharedList.sortAsync 00000045 0.44890949 [8832] MM5 [10104](R) Folder - removed 00000046 0.45639023 [8832] MM5 [10536](R) BQ: Thread[10536] is executing new task now: TSharedBase.RunAsPromiseNative 00000047 0.45854956 [8832] MM5 [10104](R) TMediaMonkeyApp.notifyCommonChange, type:folder 00000048 0.45951343 [8832] MM5 [10104](R) 10104 DB prepare SQL: SELECT ID,TrackCount FROM Folders WHERE IDMedia=? AND IDParentFolder=? AND Folder=? 00000049 0.46072549 [8832] MM5 [10104](R) 10104 DB query prepare finished, took 0. 00000050 0.46237761 [8832] MM5 [10104](R) DB exec SQL: DELETE FROM Songs WHERE Songs.IDFolder in (SELECT IDChildFolder FROM FoldersHier WHERE IDFolder=8) AND ((1)) 00000051 0.46346164 [8832] MM5 [10536](R) BQ: Thread[10536] is executing new task now: TSharedBase.RunAsPromiseNative 00000052 0.57965177 [8832] MM5 [10104](R) DB lock took 110 ms : DELETE FROM Songs WHERE Songs.IDFolder in (SELECT IDChildFolder FROM FoldersHier WHERE IDFolder=8) AND ((1)) 00000053 0.57981652 [8832] MM5 [10104](R) DB exec SQL: DELETE FROM Folders WHERE Folders.ID=8 00000054 0.58008760 [8832] MM5 [10104](R) DB lock took 0 ms : DELETE FROM Folders WHERE Folders.ID=8 00000055 0.58015293 [8832] MM5 [10104](R) 10104 DB prepare SQL: SELECT ID FROM Albums WHERE Tracks=0 00000056 0.58031589 [8832] MM5 [10104](R) 10104 DB query prepare finished, took 0. 00000057 0.58046108 [8832] MM5 [10104](R) 10104 DB prepare SQL: SELECT ID FROM Artists WHERE Tracks=0 AND Albums=0 AND Authors=0 AND Conducts=0 AND Lyrics=0 AND Products=0 AND Roles=0 AND Publishes=0 00000058 0.58069694 [8832] MM5 [10104](R) 10104 DB query prepare finished, took 15. 00000059 0.58085418 [8832] MM5 [10104](R) TMediaMonkeyApp.notifyCommonChange, type:dbfolder 00000060 3.40985489 [8832] MM5 [9892](R) Going 'Worker'to make final callback 9892 00000061 3.46335888 [8832] MM5 [10536](R) Going 'Worker'to make final callback 10536 00000062 3.58087707 [8832] MM5 [10104](R) Going 'Worker'to make final callback 10104 00000063 3.58094549 [8832] MM5 [10104](R) DB: Deleting prepared query: SELECT ID,TrackCount FROM Folders WHERE IDMedia=? AND IDParentFolder=? AND Folder=? 00000064 3.58100557 [8832] MM5 [10104](R) DB: Deleting prepared query: SELECT ID FROM Albums WHERE Tracks=0 00000065 3.58102655 [8832] MM5 [10104](R) DB: Deleting prepared query: SELECT ID FROM Artists WHERE Tracks=0 AND Albums=0 AND Authors=0 AND Conducts=0 AND Lyrics=0 AND Products=0 AND Roles=0 AND Publishes=0 00000066 6.83601236 [8832] MM5 [11084](R) Still waiting for event (callstacks) : 00000067 6.83604670 [8832] MM5 [11084](R) Wait for event ID :1, delay :60000, callstack : 00000068 6.83610725 [8832] MM5 [11084](R) Wait for event ID :1, delay :60000, callstack :