00000001 0.00000000 [48852] Win7Tools - Thumbnail - add rating stars 00000002 1.23742318 [48852] Forms: Received WM_ACTIVATEAPP 00000003 1.23745716 [48852] Forms: Accepted WM_ACTIVATEAPP + 00000004 1.23813164 [48852] Forms: RestoreTopMost: Level: 1 00000005 1.23819304 [48852] Forms: RestoreTopMost: Starting 00000006 1.23875260 [48852] Winamp simulation window received messsage 28 00000007 1.23976696 [48852] MainForm: NC Activate + 00000008 2.16283131 [48852] MM4 [49844] TImagePlus.Paint: start 00000009 2.16326594 [48852] MM4 [49844] TImagePlus.Paint: finished 00000010 2.48442435 [48852] Node Now Playing starting. 00000011 2.48465419 [48852] Node Now Playing going to clear SongList. 00000012 2.48499990 [48852] Events: Invoking event: SetMnuVisibility 00000013 2.48518276 [48852] TEventedAutoObject Created, Class: TSDBTreeNode 00000014 2.48526263 [48852] TEventedAutoObject Created, Class: TSDBTreeNode 00000015 2.48733950 [48852] TEventedAutoObject Destroying, Class: TSDBTreeNode 00000016 2.48739314 [48852] TEventedAutoObject Destroying, Class: TSDBTreeNode 00000017 2.48742890 [48852] Events: Successfully finished event: SetMnuVisibility 00000018 2.48835611 [48852] 49844 DB prepare SQL: SELECT IDView FROM NodeViews WHERE NodeType = ? 00000019 2.48842001 [48852] 49844 DB query prepare finished, took 507. 00000020 2.48844767 [48852] 49844 DB open SQL: SELECT IDView FROM NodeViews WHERE NodeType = ? 00000021 2.48866630 [48852] 49844 DB lock finished, took 1680. 00000022 2.48870730 [48852] 49844 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00000023 2.48881364 [48852] 49844 DB lock finished, took 748. 00000024 2.48900199 [48852] 49844 DB open SQL: SELECT IDView FROM NodeViews WHERE NodeType = ? 00000025 2.48908877 [48852] 49844 DB lock finished, took 544. 00000026 2.48912382 [48852] 49844 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00000027 2.48920441 [48852] 49844 DB lock finished, took 499. 00000028 2.48969531 [48852] 49844 DB open SQL: SELECT IDView FROM NodeViews WHERE NodeType = ? 00000029 2.48985076 [48852] 49844 DB lock finished, took 1151. 00000030 2.48989487 [48852] 49844 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00000031 2.48998284 [48852] 49844 DB lock finished, took 552. 00000032 2.49028468 [48852] 49844 DB open SQL: SELECT IDView FROM NodeViews WHERE NodeType = ? 00000033 2.49037480 [48852] 49844 DB lock finished, took 558. 00000034 2.49041200 [48852] 49844 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00000035 2.49049497 [48852] 49844 DB lock finished, took 509. 00000036 2.49727154 [48852] Going to fill tracklist, NodeType: 7 00000037 2.50698900 [48852] MM4 [49844] TImagePlus.Paint: start 00000038 2.50717807 [48852] MM4 [49844] TImagePlus.Paint: finished 00000039 3.01178789 [48852] Win7Tools - Thumbnail - add rating stars 00000040 6.12216330 [48852] Win7Tools - Thumbnail - add rating stars 00000041 9.23965740 [48852] Win7Tools - Thumbnail - add rating stars 00000042 12.35035801 [48852] Win7Tools - Thumbnail - add rating stars 00000043 15.42861748 [48852] Win7Tools - Thumbnail - add rating stars 00000044 18.46524429 [48852] Win7Tools - Thumbnail - add rating stars 00000045 21.58957672 [48852] Win7Tools - Thumbnail - add rating stars 00000046 24.71073532 [48852] Win7Tools - Thumbnail - add rating stars 00000047 25.90029144 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 37 00000048 25.90652084 [48852] PostponeComputerSleep: Enabled = 0 00000049 25.90773582 [48852] Thread 'UpdateDriveLetters_Var' has started 51592 00000050 25.90776062 [48852] >UpdateDriveLetters - start< 00000051 25.91996765 [48852] >UpdateDriveLetters - end< 00000052 25.91998482 [48852] Going 'UpdateDriveLetters_Var'to make final callback 51592 00000053 25.92003059 [48852] Thread 'UpdateDriveLetters_Var'has finished 51592 00000054 27.73036766 [48852] Win7Tools - Thumbnail - add rating stars 00000055 30.78048706 [48852] Win7Tools - Thumbnail - add rating stars 00000056 33.82991028 [48852] Win7Tools - Thumbnail - add rating stars 00000057 36.90994644 [48852] Win7Tools - Thumbnail - add rating stars 00000058 39.91986084 [48852] Win7Tools - Thumbnail - add rating stars 00000059 42.95993423 [48852] Win7Tools - Thumbnail - add rating stars 00000060 44.49925232 [48852] Media: DBT_DEVICEREMOVECOMPLETE 00000061 44.53484344 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 40 00000062 44.54099655 [48852] TDevices.WMDeviceChangeToAll( wParam: 32772 , lParam: 648576) 00000063 44.54233932 [48852] WMDM: Device change message 00000064 44.54253006 [48852] WMDM: Queueing action id:0 00000065 44.54277420 [48852] Media: Returned value: 1 00000066 44.54304504 [48852] WMDM: Looking for device changes... 00000067 44.54397583 [48852] Thread 'UpdateDriveLetters_Var' has started 44156 00000068 44.54409409 [48852] >UpdateDriveLetters - start< 00000069 44.54584122 [48852] Winamp Playlist sim - message 537 left to the default processing 00000070 44.54601669 [48852] Winamp simulation window received messsage 537 00000071 44.59452057 [48852] >UpdateDriveLetters - end< 00000072 44.59455490 [48852] Going 'UpdateDriveLetters_Var'to make final callback 44156 00000073 44.59459686 [48852] Thread 'UpdateDriveLetters_Var'has finished 44156 00000074 45.10238266 [48852] Shell: SHCNE_UPDATEDIR message 00000075 45.97956467 [48852] Win7Tools - Thumbnail - add rating stars 00000076 48.26896286 [48852] ANDROID DEVICE UNLOCKED ??? Re-enumerate devices: 00000077 48.26904297 [48852] TDevices.WMDeviceChangeToAll( wParam: -1 , lParam: 0) 00000078 48.27209473 [48852] WMDM: Device change message 00000079 48.27214813 [48852] WMDM: Queueing action id:0 00000080 48.27234268 [48852] WMDM: Closing Notifications 00000081 48.27237320 [48852] WMDM: Closing Notifications 2 00000082 48.27243423 [48852] WMDM: Closing Notifications 3 00000083 48.27249146 [48852] WMDM: Closing Dev manager 00000084 48.27441788 [48852] WMDM: All is terminated 00000085 48.27446747 [48852] WMDM: Creating Dev Mgr 00000086 48.27719498 [48852] WMDM: Geting auth interface 00000087 48.27723694 [48852] WMDM: End of IU 00000088 48.27729416 [48852] WMDM: Authenticating 00000089 48.28722382 [48852] WMDM: Creating Notifications 00000090 48.28726578 [48852] WMDM: Intfc queried. 00000091 48.28732300 [48852] WMDM: FindConnectionPoint ok. 00000092 48.31047821 [48852] WMDM: Notifications ok. 00000093 48.31050110 [48852] WMDM: Looking for device changes... 00000094 49.00988007 [48852] Win7Tools - Thumbnail - add rating stars 00000095 52.05962372 [48852] Win7Tools - Thumbnail - add rating stars 00000096 55.12968445 [48852] Win7Tools - Thumbnail - add rating stars 00000097 55.90444946 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 39 00000098 55.91032410 [48852] PostponeComputerSleep: Enabled = 0 00000099 55.91260910 [48852] Thread 'UpdateDriveLetters_Var' has started 43636 00000100 55.91268539 [48852] >UpdateDriveLetters - start< 00000101 55.92232132 [48852] >UpdateDriveLetters - end< 00000102 55.92234802 [48852] Going 'UpdateDriveLetters_Var'to make final callback 43636 00000103 55.92241287 [48852] Thread 'UpdateDriveLetters_Var'has finished 43636 00000104 58.17986679 [48852] Win7Tools - Thumbnail - add rating stars 00000105 61.26986313 [48852] Win7Tools - Thumbnail - add rating stars 00000106 64.33000946 [48852] Win7Tools - Thumbnail - add rating stars 00000107 67.43996429 [48852] Win7Tools - Thumbnail - add rating stars 00000108 70.47997284 [48852] Win7Tools - Thumbnail - add rating stars 00000109 73.51983643 [48852] Win7Tools - Thumbnail - add rating stars 00000110 75.36904144 [48852] MM4 [49844] Re-enumerate devices (after 30s - issue #9777): 00000111 75.36911774 [48852] TDevices.WMDeviceChangeToAll( wParam: -1 , lParam: 0) 00000112 75.37245178 [48852] WMDM: Device change message 00000113 75.37248993 [48852] WMDM: Queueing action id:0 00000114 75.37268829 [48852] WMDM: Closing Notifications 00000115 75.37276459 [48852] WMDM: Closing Notifications 2 00000116 75.37282562 [48852] WMDM: Closing Notifications 3 00000117 75.37288666 [48852] WMDM: Closing Dev manager 00000118 75.37474823 [48852] WMDM: All is terminated 00000119 75.37479401 [48852] WMDM: Creating Dev Mgr 00000120 75.37717438 [48852] WMDM: Geting auth interface 00000121 75.37719727 [48852] WMDM: End of IU 00000122 75.37725830 [48852] WMDM: Authenticating 00000123 75.38735199 [48852] WMDM: Creating Notifications 00000124 75.38737488 [48852] WMDM: Intfc queried. 00000125 75.38743591 [48852] WMDM: FindConnectionPoint ok. 00000126 75.41522217 [48852] WMDM: Notifications ok. 00000127 75.41529083 [48852] WMDM: Looking for device changes... 00000128 76.57993317 [48852] Win7Tools - Thumbnail - add rating stars 00000129 79.59000397 [48852] Win7Tools - Thumbnail - add rating stars 00000130 82.66016388 [48852] Win7Tools - Thumbnail - add rating stars 00000131 85.68032074 [48852] Win7Tools - Thumbnail - add rating stars 00000132 85.92575836 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 38 00000133 85.93193817 [48852] PostponeComputerSleep: Enabled = 0 00000134 85.93482971 [48852] Thread 'UpdateDriveLetters_Var' has started 42468 00000135 85.93492126 [48852] >UpdateDriveLetters - start< 00000136 85.94670105 [48852] >UpdateDriveLetters - end< 00000137 85.94675446 [48852] Going 'UpdateDriveLetters_Var'to make final callback 42468 00000138 85.94689941 [48852] Thread 'UpdateDriveLetters_Var'has finished 42468 00000139 88.80072021 [48852] Win7Tools - Thumbnail - add rating stars 00000140 91.90988922 [48852] Win7Tools - Thumbnail - add rating stars 00000141 94.92987061 [48852] Win7Tools - Thumbnail - add rating stars 00000142 97.98972321 [48852] Win7Tools - Thumbnail - add rating stars 00000143 101.04026794 [48852] Win7Tools - Thumbnail - add rating stars 00000144 103.02560425 [48852] MainForm: NC Activate - 00000145 103.02689362 [48852] Forms: Received WM_ACTIVATEAPP 00000146 103.02694702 [48852] Forms: Accepted WM_ACTIVATEAPP - 00000147 103.02700806 [48852] Forms: NormalizeTopMosts: Level: 0 00000148 103.02728271 [48852] Forms: NormalizeTopMost: Starting 00000149 103.02777863 [48852] Winamp simulation window received messsage 28 00000150 103.15286255 [48852] Media: DBT_DEVICEARRIVAL 00000151 103.18006897 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 39 00000152 103.18656158 [48852] TDevices.WMDeviceChangeToAll( wParam: 32768 , lParam: 648576) 00000153 103.18769836 [48852] Thread 'UpdateDriveLetters_Var' has started 27248 00000154 103.18774414 [48852] >UpdateDriveLetters - start< 00000155 103.19495392 [48852] WMDM: Device change message 00000156 103.19497681 [48852] WMDM: Queueing action id:0 00000157 103.19501495 [48852] Media: Returned value: 1 00000158 103.19512939 [48852] WMDM: Looking for device changes... 00000159 103.19655609 [48852] Winamp Playlist sim - message 537 left to the default processing 00000160 103.19672394 [48852] Winamp simulation window received messsage 537 00000161 104.07976532 [48852] Win7Tools - Thumbnail - add rating stars 00000162 106.73324585 [48852] CD: Procedure entered (GetInfoFromAudioCD), Drive letter: H 00000163 106.73328400 [48852] CD: AudioCDReadCS.Acquired, Drive letter: H 00000164 107.18518066 [48852] hpCDEBurn: On the point of reading TOC 00000165 107.22667694 [48852] hpCDEBurn: Read TOC of 0. track - LBA value: 0 00000166 107.22670746 [48852] hpCDEBurn: Read TOC of 0. track - MSF format: 0, 0, 2, 0 00000167 107.22673798 [48852] hpCDEBurn: Read TOC of 1. track - LBA value: 2744270 00000168 107.22676849 [48852] hpCDEBurn: Read TOC of 1. track - MSF format: 0, 97, 52, 20 00000169 107.22679901 [48852] CD: Going to read CD-Text. 00000170 107.22683716 [48852] hpCDEBurn: entering ReadCDText() 00000171 107.25144196 [48852] hpCDEBurn: On the point of calling pDevice->ReadCDText() 00000172 107.28189087 [48852] hpCDEBurn: pDevice->ReadCDText: res = 0 00000173 107.28190613 [48852] CD: CD-Text wasn't found. 00000174 107.28193665 [48852] CD: AudioCDReadCS.Released, Drive letter: H 00000175 107.28196716 [48852] CD: Procedure finished (GetInfoFromAudioCD) 00000176 107.30659485 [48852] TGenThread.Create: ThreadName: ReadInfoFromCD , Running Threads: Internal: 2, All: 41 00000177 107.31359863 [48852] >UpdateDriveLetters - end< 00000178 107.31368256 [48852] Going 'UpdateDriveLetters_Var'to make final callback 27248 00000179 107.31394196 [48852] Thread 'UpdateDriveLetters_Var'has finished 27248 00000180 107.31604767 [48852] Thread 'ReadInfoFromCD' has started 52240 00000181 107.31697083 [48852] CD: Procedure entered (GetInfoFromAudioCD), Drive letter: H 00000182 107.31705475 [48852] CD: AudioCDReadCS.Acquired, Drive letter: H 00000183 107.35726166 [48852] Win7Tools - Thumbnail - add rating stars 00000184 107.72381592 [48852] hpCDEBurn: On the point of reading TOC 00000185 107.76548004 [48852] hpCDEBurn: Read TOC of 0. track - LBA value: 0 00000186 107.76554108 [48852] hpCDEBurn: Read TOC of 0. track - MSF format: 0, 0, 2, 0 00000187 107.76560974 [48852] hpCDEBurn: Read TOC of 1. track - LBA value: 2744270 00000188 107.76567078 [48852] hpCDEBurn: Read TOC of 1. track - MSF format: 0, 97, 52, 20 00000189 107.76573181 [48852] CD: Going to read CD-Text. 00000190 107.76580048 [48852] hpCDEBurn: entering ReadCDText() 00000191 107.78943634 [48852] hpCDEBurn: On the point of calling pDevice->ReadCDText() 00000192 107.81500244 [48852] hpCDEBurn: pDevice->ReadCDText: res = 0 00000193 107.81506348 [48852] CD: CD-Text wasn't found. 00000194 107.81513977 [48852] CD: AudioCDReadCS.Released, Drive letter: H 00000195 107.81520844 [48852] CD: Procedure finished (GetInfoFromAudioCD) 00000196 107.82361603 [48852] CD: Procedure entered (GetInfoFromAudioCD), Drive letter: H 00000197 107.82365417 [48852] CD: AudioCDReadCS.Acquired, Drive letter: H 00000198 108.09089661 [48852] Shell: SHCNE_UPDATEDIR message 00000199 108.15655518 [48852] hpCDEBurn: On the point of reading TOC 00000200 108.19029999 [48852] hpCDEBurn: Read TOC of 0. track - LBA value: 0 00000201 108.19034576 [48852] hpCDEBurn: Read TOC of 0. track - MSF format: 0, 0, 2, 0 00000202 108.19038391 [48852] hpCDEBurn: Read TOC of 1. track - LBA value: 2744270 00000203 108.19041443 [48852] hpCDEBurn: Read TOC of 1. track - MSF format: 0, 97, 52, 20 00000204 108.19043732 [48852] CD: Going to read CD-Text. 00000205 108.19046021 [48852] hpCDEBurn: entering ReadCDText() 00000206 108.20603943 [48852] hpCDEBurn: On the point of calling pDevice->ReadCDText() 00000207 108.24088287 [48852] hpCDEBurn: pDevice->ReadCDText: res = 0 00000208 108.24092102 [48852] CD: CD-Text wasn't found. 00000209 108.24095917 [48852] CD: AudioCDReadCS.Released, Drive letter: H 00000210 108.24099731 [48852] CD: Procedure finished (GetInfoFromAudioCD) 00000211 108.24111176 [48852] 52240 DB open SQL: SELECT * FROM Medias WHERE SerialNumber=1451913822 00000212 108.24114990 [48852] OpenQuery - Preparing query SELECT * FROM Medias WHERE SerialNumber=1451913822 00000213 108.24137878 [48852] 52240 DB lock finished, took 2323. 00000214 108.24163818 [48852] Going 'ReadInfoFromCD'to make final callback 52240 00000215 108.24171448 [48852] Thread 'ReadInfoFromCD'has finished 52240 00000216 108.40410614 [48852] Shell: Media Inserted message 00000217 108.40417480 [48852] TDevices.WMDeviceChangeToAll( wParam: -1 , lParam: 0) 00000218 108.40676117 [48852] WMDM: Device change message 00000219 108.40683746 [48852] WMDM: Queueing action id:0 00000220 108.40691376 [48852] WMDM: Closing Notifications 00000221 108.40701294 [48852] WMDM: Closing Notifications 2 00000222 108.40710449 [48852] WMDM: Closing Notifications 3 00000223 108.40716553 [48852] WMDM: Closing Dev manager 00000224 108.40742493 [48852] Shell: SHCNE_UPDATEDIR message 00000225 108.40893555 [48852] Shell: SHCNE_UPDATEDIR message 00000226 108.41029358 [48852] WMDM: All is terminated 00000227 108.41048431 [48852] WMDM: Creating Dev Mgr 00000228 108.41108704 [48852] WMDM: Geting auth interface 00000229 108.41116333 [48852] WMDM: End of IU 00000230 108.41122437 [48852] WMDM: Authenticating 00000231 108.41669464 [48852] WMDM: Creating Notifications 00000232 108.41673279 [48852] WMDM: Intfc queried. 00000233 108.41677094 [48852] WMDM: FindConnectionPoint ok. 00000234 108.44163513 [48852] WMDM: Notifications ok. 00000235 108.44166565 [48852] WMDM: Looking for device changes... 00000236 110.43981171 [48852] Win7Tools - Thumbnail - add rating stars 00000237 111.47893524 [48852] ANDROID DEVICE UNLOCKED ??? Re-enumerate devices: 00000238 111.47901154 [48852] TDevices.WMDeviceChangeToAll( wParam: -1 , lParam: 0) 00000239 111.48199463 [48852] WMDM: Device change message 00000240 111.48207092 [48852] WMDM: Queueing action id:0 00000241 111.48223877 [48852] WMDM: Closing Notifications 00000242 111.48234558 [48852] WMDM: Closing Notifications 2 00000243 111.48238373 [48852] WMDM: Closing Notifications 3 00000244 111.48242950 [48852] WMDM: Closing Dev manager 00000245 111.48423767 [48852] WMDM: All is terminated 00000246 111.48429108 [48852] WMDM: Creating Dev Mgr 00000247 111.48492432 [48852] WMDM: Geting auth interface 00000248 111.48499298 [48852] WMDM: End of IU 00000249 111.48505402 [48852] WMDM: Authenticating 00000250 111.49500275 [48852] WMDM: Creating Notifications 00000251 111.49506378 [48852] WMDM: Intfc queried. 00000252 111.49511719 [48852] WMDM: FindConnectionPoint ok. 00000253 111.52357483 [48852] WMDM: Notifications ok. 00000254 111.52363586 [48852] WMDM: Looking for device changes... 00000255 113.56003571 [48852] Win7Tools - Thumbnail - add rating stars 00000256 115.92427826 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 38 00000257 115.93035889 [48852] PostponeComputerSleep: Enabled = 0 00000258 115.93270111 [48852] Thread 'UpdateDriveLetters_Var' has started 52080 00000259 115.93277740 [48852] >UpdateDriveLetters - start< 00000260 115.94795227 [48852] >UpdateDriveLetters - end< 00000261 115.94800568 [48852] Going 'UpdateDriveLetters_Var'to make final callback 52080 00000262 115.94809723 [48852] Thread 'UpdateDriveLetters_Var'has finished 52080 00000263 116.59988403 [48852] Win7Tools - Thumbnail - add rating stars 00000264 119.61984253 [48852] Win7Tools - Thumbnail - add rating stars 00000265 122.74041748 [48852] Win7Tools - Thumbnail - add rating stars 00000266 125.80087280 [48852] Win7Tools - Thumbnail - add rating stars 00000267 128.81973267 [48852] Win7Tools - Thumbnail - add rating stars 00000268 131.88018799 [48852] Win7Tools - Thumbnail - add rating stars 00000269 133.49897766 [48852] MM4 [49844] Re-enumerate devices (after 30s - issue #9777): 00000270 133.49905396 [48852] TDevices.WMDeviceChangeToAll( wParam: -1 , lParam: 0) 00000271 133.50210571 [48852] WMDM: Device change message 00000272 133.50218201 [48852] WMDM: Queueing action id:0 00000273 133.50233459 [48852] WMDM: Closing Notifications 00000274 133.50242615 [48852] WMDM: Closing Notifications 2 00000275 133.50248718 [48852] WMDM: Closing Notifications 3 00000276 133.50254822 [48852] WMDM: Closing Dev manager 00000277 133.50419617 [48852] WMDM: All is terminated 00000278 133.50424194 [48852] WMDM: Creating Dev Mgr 00000279 133.50489807 [48852] WMDM: Geting auth interface 00000280 133.50495911 [48852] WMDM: End of IU 00000281 133.50502014 [48852] WMDM: Authenticating 00000282 133.51502991 [48852] WMDM: Creating Notifications 00000283 133.51509094 [48852] WMDM: Intfc queried. 00000284 133.51516724 [48852] WMDM: FindConnectionPoint ok. 00000285 133.54479980 [48852] WMDM: Notifications ok. 00000286 133.54484558 [48852] WMDM: Looking for device changes... 00000287 134.97996521 [48852] Win7Tools - Thumbnail - add rating stars 00000288 138.07969666 [48852] Win7Tools - Thumbnail - add rating stars 00000289 141.19976807 [48852] Win7Tools - Thumbnail - add rating stars 00000290 144.26007080 [48852] Win7Tools - Thumbnail - add rating stars 00000291 145.89364624 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 36 00000292 145.89979553 [48852] PostponeComputerSleep: Enabled = 0 00000293 145.90284729 [48852] Thread 'UpdateDriveLetters_Var' has started 52024 00000294 145.90296936 [48852] >UpdateDriveLetters - start< 00000295 145.91763306 [48852] >UpdateDriveLetters - end< 00000296 145.91766357 [48852] Going 'UpdateDriveLetters_Var'to make final callback 52024 00000297 145.91770935 [48852] Thread 'UpdateDriveLetters_Var'has finished 52024 00000298 147.34001160 [48852] Win7Tools - Thumbnail - add rating stars 00000299 150.39999390 [48852] Win7Tools - Thumbnail - add rating stars 00000300 153.46017456 [48852] Win7Tools - Thumbnail - add rating stars 00000301 156.57543945 [48852] Win7Tools - Thumbnail - add rating stars 00000302 158.57920837 [48852] BQ: Added new task. Currently 1 tasks in queue. 00000303 158.57926941 [48852] BQ: Starting a new task. 00000304 158.57934570 [48852] BQ: Currently running 0 threads of 1 00000305 158.57940674 [48852] BQ: Starting a new thread. 00000306 158.61848450 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 1, All: 37 00000307 158.62541199 [48852] Thread 'BackgroundQueue' has started 51656 00000308 158.62553406 [48852] 51656 DB exec SQL: UPDATE Songs SET LastTimePlayed=43497.768359803, TrackModified=43497.768359803 WHERE Id=361310 00000309 158.62559509 [48852] 51656 DB lock successful. 00000310 158.63809204 [48852] 51656 DB lock finished, took 123858. 00000311 158.96537781 [48852] Win7Tools - Thumbnail - add rating stars 00000312 158.97041321 [48852] Win7Tools - Thumbnail - add rating stars 00000313 158.97349548 [48852] MM4 [49844] TImagePlus.Paint: start 00000314 158.97396851 [48852] MM4 [49844] TImagePlus.Paint: finished 00000315 159.03015137 [48852] 49844 DB open SQL: SELECT ID, Name, View FROM Views ORDER BY ID 00000316 159.03033447 [48852] 49844 DB lock finished, took 1408. 00000317 159.04435730 [48852] 49844 DB open SQL: SELECT * FROM Filters ORDER BY Pos 00000318 159.04460144 [48852] 49844 DB lock finished, took 1999. 00000319 159.57902527 [48852] BQ: Added new task. Currently 1 tasks in queue. 00000320 159.57908630 [48852] BQ: Starting a new task. 00000321 159.57914734 [48852] BQ: There are threads waiting, resume one. 00000322 159.57931519 [48852] 51656 DB open SQL: SELECT Songs.ID FROM Songs WHERE ( Songs.TrackType in (4) ) LIMIT 1 00000323 159.57966614 [48852] 51656 DB lock finished, took 2721. 00000324 162.04980469 [48852] Win7Tools - Thumbnail - add rating stars 00000325 162.58865356 [48852] Going 'BackgroundQueue'to make final callback 51656 00000326 162.58877563 [48852] Thread 'BackgroundQueue'has finished 51656 00000327 165.05986023 [48852] Win7Tools - Thumbnail - add rating stars 00000328 168.06988525 [48852] Win7Tools - Thumbnail - add rating stars 00000329 171.15983582 [48852] Win7Tools - Thumbnail - add rating stars 00000330 174.19992065 [48852] Win7Tools - Thumbnail - add rating stars 00000331 175.92463684 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 37 00000332 175.93077087 [48852] PostponeComputerSleep: Enabled = 0 00000333 175.93220520 [48852] Thread 'UpdateDriveLetters_Var' has started 43912 00000334 175.93226624 [48852] >UpdateDriveLetters - start< 00000335 175.94546509 [48852] >UpdateDriveLetters - end< 00000336 175.94549561 [48852] Going 'UpdateDriveLetters_Var'to make final callback 43912 00000337 175.94554138 [48852] Thread 'UpdateDriveLetters_Var'has finished 43912 00000338 177.22491455 [48852] Win7Tools - Thumbnail - add rating stars 00000339 180.28990173 [48852] Win7Tools - Thumbnail - add rating stars 00000340 183.36033630 [48852] Win7Tools - Thumbnail - add rating stars 00000341 186.41703796 [48852] Win7Tools - Thumbnail - add rating stars 00000342 189.53990173 [48852] Win7Tools - Thumbnail - add rating stars 00000343 192.58711243 [48852] Win7Tools - Thumbnail - add rating stars 00000344 195.64805603 [48852] Win7Tools - Thumbnail - add rating stars 00000345 198.76069641 [48852] Win7Tools - Thumbnail - add rating stars 00000346 201.79119873 [48852] Win7Tools - Thumbnail - add rating stars 00000347 204.82966614 [48852] Win7Tools - Thumbnail - add rating stars 00000348 205.90823364 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 36 00000349 205.91706848 [48852] PostponeComputerSleep: Enabled = 0 00000350 205.92004395 [48852] Thread 'UpdateDriveLetters_Var' has started 36188 00000351 205.92013550 [48852] >UpdateDriveLetters - start< 00000352 205.93524170 [48852] >UpdateDriveLetters - end< 00000353 205.93531799 [48852] Going 'UpdateDriveLetters_Var'to make final callback 36188 00000354 205.93544006 [48852] Thread 'UpdateDriveLetters_Var'has finished 36188 00000355 207.87016296 [48852] Win7Tools - Thumbnail - add rating stars 00000356 210.92990112 [48852] Win7Tools - Thumbnail - add rating stars 00000357 213.97004700 [48852] Win7Tools - Thumbnail - add rating stars 00000358 217.05026245 [48852] Win7Tools - Thumbnail - add rating stars 00000359 220.09031677 [48852] Win7Tools - Thumbnail - add rating stars 00000360 223.15013123 [48852] Win7Tools - Thumbnail - add rating stars 00000361 226.18588257 [48852] Win7Tools - Thumbnail - add rating stars 00000362 229.21997070 [48852] Win7Tools - Thumbnail - add rating stars 00000363 232.26440430 [48852] Win7Tools - Thumbnail - add rating stars 00000364 235.36985779 [48852] Win7Tools - Thumbnail - add rating stars 00000365 235.90844727 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 38 00000366 235.91728210 [48852] PostponeComputerSleep: Enabled = 0 00000367 235.92030334 [48852] Thread 'UpdateDriveLetters_Var' has started 50340 00000368 235.92041016 [48852] >UpdateDriveLetters - start< 00000369 235.93536377 [48852] >UpdateDriveLetters - end< 00000370 235.93540955 [48852] Going 'UpdateDriveLetters_Var'to make final callback 50340 00000371 235.93551636 [48852] Thread 'UpdateDriveLetters_Var'has finished 50340 00000372 238.46997070 [48852] Win7Tools - Thumbnail - add rating stars 00000373 241.59001160 [48852] Win7Tools - Thumbnail - add rating stars 00000374 244.65016174 [48852] Win7Tools - Thumbnail - add rating stars 00000375 247.08868408 [48852] IntPlay: Play thread Finishing Playback 00000376 247.08876038 [48852] WASAPI: Close starts 00000377 247.08882141 [48852] WASAPI: Going to crossfade 00000378 247.08886719 [48852] WASAPI: Close ends 00000379 247.08897400 [48852] Going to execute format plug-in destructor. 00000380 247.08901978 [48852] FLAC: FORMAT_DecodeClose(). 00000381 247.08973694 [48852] IntPlay: Play thread Exit 00000382 247.08981323 [48852] Going 'PlayThreadProc'to make final callback 25576 00000383 247.08995056 [48852] Thread 'PlayThreadProc'has finished 25576 00000384 247.09010315 [48852] BQ: Added new task. Currently 1 tasks in queue. 00000385 247.09017944 [48852] BQ: Starting a new task. 00000386 247.09025574 [48852] BQ: Currently running 0 threads of 1 00000387 247.09030151 [48852] BQ: Starting a new thread. 00000388 247.12942505 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 0, All: 39 00000389 247.13960266 [48852] Thread 'BackgroundQueue' has started 50772 00000390 247.13973999 [48852] 50772 DB exec SQL: INSERT INTO Played (IdSong,PlayDate,UTCOffset) VALUES (361310,43497.769384282,-0.333333333) 00000391 247.13981628 [48852] 50772 DB lock successful. 00000392 247.13986206 [48852] 49844 DB open SQL: Select * FROM Filters Order BY ID 00000393 247.15493774 [48852] 50772 DB lock finished, took 150373. 00000394 247.15499878 [48852] OpenQuery - Preparing query Select * FROM Filters Order BY ID 00000395 247.15534973 [48852] 50772 DB exec SQL: UPDATE Songs SET PlayCounter=1,LastTimePlayed=43497.769384282, TrackModified=43497.769384282, PlaybackPos = 0 WHERE Id=361310 00000396 247.15541077 [48852] 49844 DB lock finished, took 154446. 00000397 247.15545654 [48852] 50772 DB lock successful. 00000398 247.16738892 [48852] 50772 DB lock finished, took 118827. 00000399 247.16795349 [48852] Player: Next command started 00000400 247.16802979 [48852] _Stop: started 00000401 247.20701599 [48852] BQ: Added new task. Currently 1 tasks in queue. 00000402 247.20870972 [48852] BQ: Starting a new task. 00000403 247.20927429 [48852] BQ: Currently running 1 threads of 1 00000404 247.20982361 [48852] BQ: A new thread isn't needed. 00000405 247.21038818 [48852] PrepareDockedVideo: Begin 00000406 247.21093750 [48852] PrepareDockedVideo: Switching=true IsStartingPlayback=false WasManuallyChanged=false 00000407 247.21148682 [48852] _Stop: finished 00000408 247.21208191 [48852] Player: Setting current track: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00000409 247.21264648 [48852] Player: Next track prepared, going to start playback 00000410 247.24406433 [48852] TGenThread.Create: ThreadName: PlaybackStarter_Var , Running Threads: Internal: 1, All: 40 00000411 247.25328064 [48852] PrepareDockedVideo: Begin 00000412 247.25332642 [48852] PrepareDockedVideo: Switching=true IsStartingPlayback=true WasManuallyChanged=true 00000413 247.25337219 [48852] Remaining Cover Lists: 0 00000414 247.25340271 [48852] BQ: Added new task. Currently 2 tasks in queue. 00000415 247.25344849 [48852] BQ: Starting a new task. 00000416 247.25347900 [48852] BQ: Currently running 1 threads of 8 00000417 247.25352478 [48852] BQ: Starting a new thread. 00000418 247.25567627 [48852] Thread 'PlaybackStarter_Var' has started 8240 00000419 247.25575256 [48852] Player: _Play() procedure entering. 00000420 247.26167297 [48852] Player: W7 icon updated. 00000421 247.26174927 [48852] Player: Going to handle the current track. 00000422 247.26187134 [48852] Player: Updating playlist entry. 00000423 247.26194763 [48852] Player: Setting current track: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00000424 247.26205444 [48852] Player: Track entry prepared, going to start playback. 00000425 247.26216125 [48852] Player: Song is not cached, try to play the original file 00000426 247.26266479 [48852] Going to play file: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00000427 247.26280212 [48852] Decoder: CreateDecoder() started 00000428 247.26287842 [48852] Going to execute format plug-in constructor. 00000429 247.28004456 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 1, All: 41 00000430 247.28550720 [48852] 49844 DB open SQL: SELECT Lyrics, Comment FROM Songs WHERE Songs.ID=? 00000431 247.28565979 [48852] 49844 DB lock finished, took 1096. 00000432 247.28747559 [48852] Thread 'BackgroundQueue' has started 13476 00000433 247.31022644 [48852] TGenThread.Create: ThreadName: SearchLyricsOnBackgroud_Var , Running Threads: Internal: 2, All: 42 00000434 247.31430054 [48852] MM4 [13476] UpdateSongPictures: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00000435 247.31445313 [48852] Added Cover Lists: 1 00000436 247.31452942 [48852] GetFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00000437 247.31463623 [48852] GetFileInfo: readPictures=spAlways 00000438 247.31474304 [48852] GetFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00000439 247.31515503 [48852] FH.ReadFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00000440 247.31524658 [48852] f_flac: FORMAT_OpenFile 00000441 247.31697083 [48852] FH.ReadFileInfo openned 00000442 247.31730652 [48852] Added Covers: 2 00000443 247.31750488 [48852] f_flac: FORMAT_CloseFile 00000444 247.31803894 [48852] 13476 DB prepare SQL: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00000445 247.31848145 [48852] 13476 DB query prepare finished, took 3074. 00000446 247.31860352 [48852] 13476 DB open SQL: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00000447 247.31883240 [48852] MM4 [49844] TLyricsScroller.createOverlay: rows: 2 00000448 247.31906128 [48852] 13476 DB lock finished, took 3401. 00000449 247.31929016 [48852] MM4 [49844] TLyricsScroller.createOverlay: finished 00000450 247.31950378 [48852] GetFileInfo: Found in DB 00000451 247.31976318 [48852] MM4 [49844] TLyricsScroller.createOverlay: rows: 2 00000452 247.31996155 [48852] MM4 [13476] UpdateSongPictures: CoverList.LoadForSongId, D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00000453 247.32019043 [48852] 13476 DB open SQL: SELECT * FROM Covers WHERE IDSong=361311 ORDER BY CoverOrder 00000454 247.32040405 [48852] OpenQuery - Preparing query SELECT * FROM Covers WHERE IDSong=361311 ORDER BY CoverOrder 00000455 247.32072449 [48852] 13476 DB lock finished, took 3477. 00000456 247.32087708 [48852] Added Covers: 3 00000457 247.32090759 [48852] Remaining Covers: 2 00000458 247.32101440 [48852] Thread 'SearchLyricsOnBackgroud_Var' has started 42792 00000459 247.32127380 [48852] MM4 [49844] TLyricsScroller.createOverlay: finished 00000460 247.32157898 [48852] Current User Scripts Folder: C:\Users\mwarn\AppData\Roaming\MediaMonkey\Scripts\ 00000461 247.32199097 [48852] MM4 [49844] TImagePlus.Paint: start 00000462 247.32249451 [48852] MM4 [49844] TImagePlus.Paint: finished 00000463 247.34082031 [48852] MM4 [49844] TImagePlus.Paint: start 00000464 247.34112549 [48852] MM4 [49844] TImagePlus.Paint: finished 00000465 247.37132263 [48852] Win7Tools - Thumbnail - new size set 00000466 247.39682007 [48852] TGenThread.Create: ThreadName: anonymous , Running Threads: Internal: 3, All: 43 00000467 247.40435791 [48852] Winamp simulation window received messsage 12 00000468 247.40454102 [48852] BQ: Added new task. Currently 2 tasks in queue. 00000469 247.40467834 [48852] BQ: Starting a new task. 00000470 247.40476990 [48852] BQ: Currently running 2 threads of 8 00000471 247.40490723 [48852] BQ: Starting a new thread. 00000472 247.40499878 [48852] Thread 'anonymous' has started 50664 00000473 247.40547180 [48852] MM4 [50664] UpdateSongPictures: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00000474 247.40551758 [48852] Added Cover Lists: 2 00000475 247.40559387 [48852] GetFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00000476 247.40563965 [48852] GetFileInfo: readPictures=spAlways 00000477 247.40570068 [48852] GetFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00000478 247.40582275 [48852] FH.ReadFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00000479 247.40585327 [48852] f_flac: FORMAT_OpenFile 00000480 247.40631104 [48852] FH.ReadFileInfo openned 00000481 247.40638733 [48852] Added Covers: 3 00000482 247.40643311 [48852] f_flac: FORMAT_CloseFile 00000483 247.40666199 [48852] 50664 DB prepare SQL: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00000484 247.40687561 [48852] 50664 DB query prepare finished, took 1702. 00000485 247.40692139 [48852] 50664 DB open SQL: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00000486 247.40699768 [48852] TScriptExec.RunProcedure: SearchLyrics 00000487 247.40710449 [48852] 50664 DB lock finished, took 1295. 00000488 247.40722656 [48852] GetFileInfo: Found in DB 00000489 247.40725708 [48852] MM4 [50664] UpdateSongPictures: CoverList.LoadForSongId, D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00000490 247.40730286 [48852] 50664 DB open SQL: SELECT * FROM Covers WHERE IDSong=361311 ORDER BY CoverOrder 00000491 247.40736389 [48852] OpenQuery - Preparing query SELECT * FROM Covers WHERE IDSong=361311 ORDER BY CoverOrder 00000492 247.40748596 [48852] 50664 DB lock finished, took 1398. 00000493 247.40753174 [48852] Added Covers: 4 00000494 247.40756226 [48852] lyricsSearch.js: SearchLyrics: Artist: Bruce Cockburn ,Title: Pacing The Cage ,currentRequest = 0 00000495 247.40762329 [48852] Remaining Covers: 3 00000496 247.40763855 [48852] lyricsSearch.js: init 00000497 247.40771484 [48852] lyricsSearch.js: whatNext init 00000498 247.40777588 [48852] lyricsSearch.js: Calling search send 00000499 247.40782166 [48852] lyricsSearch.js: SearchSend 00000500 247.40884399 [48852] TIndyHTTP.GetResponseContent started: URL: http://lyrics.wikia.com/wiki/Bruce_Cockburn:Pacing_The_Cage, RequestBody: 00000501 247.43595886 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 3, All: 45 00000502 247.44400024 [48852] Thread 'BackgroundQueue' has started 48960 00000503 247.44412231 [48852] 48960 DB open SQL: SELECT Playlists.IDPlaylist, Playlists.PlaylistName FROM Playlists WHERE Playlists.IDPlaylist IN (SELECT PlaylistSongs.IDPlaylist FROM PlaylistSongs WHERE PlaylistSongs.IDSong IN (SELECT ID FROM Songs ORDER BY LastTimePlayed DESC LIMIT 200) GROUP BY PlaylistSongs.IDPlaylist) LIMIT 10 00000504 247.44419861 [48852] OpenQuery - Preparing query SELECT Playlists.IDPlaylist, Playlists.PlaylistName FROM Playlists WHERE Playlists.IDPlaylist IN (SELECT PlaylistSongs.IDPlaylist FROM PlaylistSongs WHERE PlaylistSongs.IDSong IN (SELECT ID FROM Songs ORDER BY LastTimePlayed DESC LIMIT 200) GROUP BY PlaylistSongs.IDPlaylist) LIMIT 10 00000505 247.44596863 [48852] 48960 DB lock finished, took 17463. 00000506 247.45062256 [48852] PrepareDockedVideo: Begin 00000507 247.45065308 [48852] PrepareDockedVideo: Switching=true IsStartingPlayback=true WasManuallyChanged=true 00000508 247.45072937 [48852] PrepareDockedVideo: Begin 00000509 247.45074463 [48852] PrepareDockedVideo: Switching=true IsStartingPlayback=true WasManuallyChanged=false 00000510 247.45185852 [48852] FLAC: FORMAT_DecodeInit(). 00000511 247.45193481 [48852] FLAC: Going to create stream decoder. 00000512 247.45202637 [48852] FLAC: Stream decoder created. 00000513 247.45242310 [48852] FLAC: Calling FLAC__stream_decoder_init_stream(). 00000514 247.45249939 [48852] FLAC: Calling FLAC__stream_decoder_process_until_end_of_metadata(). 00000515 247.45259094 [48852] FLAC: StreamDecoderMetadataCallback. 00000516 247.45315552 [48852] FLAC: FORMAT_DecodeInit() finished. 00000517 247.45323181 [48852] Format plug-in constructor finished. 00000518 247.45330811 [48852] Decoder: CreateDecoder() finished successfuly 00000519 247.46958923 [48852] MM4 [49844] TStretcher.PerformStretch: Threads[5], source[600, 545], target[160,145] 00000520 247.46965027 [48852] BQ: Added new task. Currently 2 tasks in queue. 00000521 247.46972656 [48852] BQ: Starting a new task. 00000522 247.46980286 [48852] BQ: Currently running 3 threads of 8 00000523 247.46987915 [48852] BQ: Starting a new thread. 00000524 247.52737427 [48852] TGenThread.Create: ThreadName: PlayThreadProc , Running Threads: Internal: 5, All: 46 00000525 247.53558350 [48852] Thread 'PlayThreadProc' has started 47288 00000526 247.53564453 [48852] IntPlay: Play thread Enter 00000527 247.53572083 [48852] IntPlay: Play thread Open Output 00000528 247.53576660 [48852] WASAPI: MMOpen started. 00000529 247.53582764 [48852] WASAPI: Start new track in thread. 00000530 247.53587341 [48852] WASAPI: Playback of a new track starts 00000531 247.53590393 [48852] WASAPI: Reusing old buffer 00000532 247.53594971 [48852] WASAPI: Track is going to be played 00000533 247.53599548 [48852] WASAPI: MMOpen finished. 00000534 247.53607178 [48852] IntPlay: Play thread Set Stream Info 00000535 247.54229736 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 5, All: 46 00000536 247.54872131 [48852] BQ: Added new task. Currently 3 tasks in queue. 00000537 247.54875183 [48852] BQ: Starting a new task. 00000538 247.54879761 [48852] BQ: Currently running 4 threads of 8 00000539 247.54885864 [48852] BQ: Starting a new thread. 00000540 247.54988098 [48852] Thread 'BackgroundQueue' has started 53124 00000541 247.55404663 [48852] IntPlay: Play thread SRate set 00000542 247.55415344 [48852] IntPlay: Play thread Set Volume 00000543 247.55419922 [48852] IntPlay: Play thread Main loop start 00000544 247.55426025 [48852] Player: Playback started 00000545 247.58248901 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 6, All: 48 00000546 247.58876038 [48852] BQ: Added new task. Currently 4 tasks in queue. 00000547 247.58879089 [48852] BQ: Starting a new task. 00000548 247.58880615 [48852] BQ: Currently running 5 threads of 8 00000549 247.58883667 [48852] BQ: Starting a new thread. 00000550 247.58988953 [48852] Thread 'BackgroundQueue' has started 14176 00000551 247.62173462 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 7, All: 49 00000552 247.62731934 [48852] BQ: Added new task. Currently 3 tasks in queue. 00000553 247.62733459 [48852] BQ: Starting a new task. 00000554 247.62736511 [48852] BQ: There are threads waiting, resume one. 00000555 247.62744141 [48852] MM4 [49844] TStretcher.PerformStretch: Finished 00000556 247.62959290 [48852] Thread 'BackgroundQueue' has started 11300 00000557 247.63522339 [48852] Win7Tools - Thumbnail - Cover should be loaded 00000558 247.63528442 [48852] Win7Tools - Thumbnail - Loading cover 00000559 247.64266968 [48852] MM4 [49844] TStretcher.PerformStretch: Threads[3], source[600, 545], target[106,96] 00000560 247.64270020 [48852] BQ: Added new task. Currently 1 tasks in queue. 00000561 247.64273071 [48852] BQ: Starting a new task. 00000562 247.64274597 [48852] BQ: There are threads waiting, resume one. 00000563 247.64277649 [48852] BQ: Added new task. Currently 2 tasks in queue. 00000564 247.64280701 [48852] BQ: Starting a new task. 00000565 247.64282227 [48852] BQ: There are threads waiting, resume one. 00000566 247.64750671 [48852] MM4 [49844] TStretcher.PerformStretch: Finished 00000567 247.64794922 [48852] Win7Tools - Thumbnail - add rating stars 00000568 247.64828491 [48852] Remaining Cover Lists: 1 00000569 247.64833069 [48852] Remaining Covers: 2 00000570 247.64846802 [48852] Going 'anonymous'to make final callback 50664 00000571 247.64855957 [48852] DB: Deleting prepared query: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00000572 247.64871216 [48852] Thread 'anonymous'has finished 50664 00000573 247.64874268 [48852] Winamp Playlist sim - WM_USER message 26 00000574 247.64878845 [48852] Winamp Playlist sim - message left to the default processing 00000575 247.64889526 [48852] Winamp Playlist sim - WM_USER message 1073741850 00000576 247.64894104 [48852] Winamp Playlist sim - message left to the default processing 00000577 247.65290833 [48852] 49844 DB open SQL: Select * FROM Filters Order BY ID 00000578 247.65298462 [48852] OpenQuery - Preparing query Select * FROM Filters Order BY ID 00000579 247.65330505 [48852] 49844 DB lock finished, took 2989. 00000580 247.65391541 [48852] Going 'PlaybackStarter_Var'to make final callback 8240 00000581 247.65396118 [48852] Thread 'PlaybackStarter_Var'has finished 8240 00000582 247.65414429 [48852] Remaining Covers: 1 00000583 247.65429688 [48852] 29432 DB prepare SQL: SELECT * FROM Filters WHERE ID=? 00000584 247.65429688 [48852] BQ: Added new task. Currently 1 tasks in queue. 00000585 247.65440369 [48852] 29432 DB query prepare finished, took 491. 00000586 247.65441895 [48852] BQ: Starting a new task. 00000587 247.65444946 [48852] BQ: There are threads waiting, resume one. 00000588 247.65449524 [48852] 29432 DB open SQL: SELECT * FROM Filters WHERE ID=? 00000589 247.65473938 [48852] 29432 DB lock finished, took 1538. 00000590 247.65478516 [48852] MM4 [49844] TImagePlus.Paint: start 00000591 247.65490723 [48852] 29432 DB prepare SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00000592 247.65501404 [48852] 29432 DB query prepare finished, took 416. 00000593 247.65509033 [48852] 29432 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00000594 247.65512085 [48852] MM4 [49844] TImagePlus.Paint: finished 00000595 247.65519714 [48852] 29432 DB lock finished, took 174. 00000596 247.65606689 [48852] 29432 DB open SQL: SELECT * FROM Filters WHERE ID=? 00000597 247.65629578 [48852] 29432 DB lock finished, took 1373. 00000598 247.65641785 [48852] 29432 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00000599 247.65649414 [48852] 29432 DB lock finished, took 133. 00000600 247.65734863 [48852] 29432 DB open SQL: SELECT Songs.* 00000601 247.65734863 [48852] FROM Songs 00000602 247.65734863 [48852] WHERE Songs.id=361311 AND Songs.TrackType in (4) 00000603 247.65739441 [48852] OpenQuery - Preparing query SELECT Songs.* 00000604 247.65739441 [48852] FROM Songs 00000605 247.65739441 [48852] WHERE Songs.id=361311 AND Songs.TrackType in (4) 00000606 247.65792847 [48852] 29432 DB lock finished, took 5122. 00000607 247.65806580 [48852] 29432 DB open SQL: SELECT * FROM Filters WHERE ID=? 00000608 247.65826416 [48852] 29432 DB lock finished, took 1253. 00000609 247.65841675 [48852] 29432 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00000610 247.65849304 [48852] 29432 DB lock finished, took 151. 00000611 247.65936279 [48852] 29432 DB open SQL: SELECT * FROM Filters WHERE ID=? 00000612 247.65957642 [48852] 29432 DB lock finished, took 1416. 00000613 247.65969849 [48852] 29432 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00000614 247.65977478 [48852] 29432 DB lock finished, took 138. 00000615 247.66059875 [48852] 29432 DB open SQL: SELECT Songs.* 00000616 247.66059875 [48852] FROM Songs 00000617 247.66059875 [48852] WHERE Songs.id=361311 AND Songs.TrackType in (1,4,5,6,7) 00000618 247.66067505 [48852] OpenQuery - Preparing query SELECT Songs.* 00000619 247.66067505 [48852] FROM Songs 00000620 247.66067505 [48852] WHERE Songs.id=361311 AND Songs.TrackType in (1,4,5,6,7) 00000621 247.66120911 [48852] 29432 DB lock finished, took 5144. 00000622 247.66133118 [48852] 29432 DB open SQL: SELECT * FROM Filters WHERE ID=? 00000623 247.66154480 [48852] 29432 DB lock finished, took 1244. 00000624 247.66166687 [48852] 29432 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00000625 247.66174316 [48852] 29432 DB lock finished, took 140. 00000626 247.66256714 [48852] 29432 DB open SQL: SELECT * FROM Filters WHERE ID=? 00000627 247.66276550 [48852] 29432 DB lock finished, took 1267. 00000628 247.66291809 [48852] 29432 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00000629 247.66299438 [48852] 29432 DB lock finished, took 127. 00000630 247.66378784 [48852] 29432 DB open SQL: SELECT Songs.* 00000631 247.66378784 [48852] FROM Songs 00000632 247.66378784 [48852] WHERE Songs.id=361311 AND ((Songs.SongPath like '%\TV\%')) 00000633 247.66387939 [48852] OpenQuery - Preparing query SELECT Songs.* 00000634 247.66387939 [48852] FROM Songs 00000635 247.66387939 [48852] WHERE Songs.id=361311 AND ((Songs.SongPath like '%\TV\%')) 00000636 247.66435242 [48852] 29432 DB lock finished, took 4808. 00000637 247.66448975 [48852] 29432 DB open SQL: SELECT * FROM Filters WHERE ID=? 00000638 247.66468811 [48852] 29432 DB lock finished, took 1208. 00000639 247.66482544 [48852] 29432 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00000640 247.66491699 [48852] 29432 DB lock finished, took 167. 00000641 247.66592407 [48852] 29432 DB open SQL: SELECT * FROM Filters WHERE ID=? 00000642 247.66612244 [48852] 29432 DB lock finished, took 1275. 00000643 247.66627502 [48852] 29432 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00000644 247.66635132 [48852] 29432 DB lock finished, took 152. 00000645 247.66728210 [48852] 29432 DB open SQL: SELECT Songs.* 00000646 247.66728210 [48852] FROM Songs 00000647 247.66728210 [48852] WHERE Songs.id=361311 AND ((Songs.SongPath like '%\Movies\%')) 00000648 247.66735840 [48852] OpenQuery - Preparing query SELECT Songs.* 00000649 247.66735840 [48852] FROM Songs 00000650 247.66735840 [48852] WHERE Songs.id=361311 AND ((Songs.SongPath like '%\Movies\%')) 00000651 247.66784668 [48852] 29432 DB lock finished, took 4703. 00000652 247.66796875 [48852] 29432 DB open SQL: SELECT * FROM Filters WHERE ID=? 00000653 247.66816711 [48852] 29432 DB lock finished, took 1214. 00000654 247.66831970 [48852] 29432 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00000655 247.66839600 [48852] 29432 DB lock finished, took 135. 00000656 247.66914368 [48852] 29432 DB open SQL: SELECT * FROM Filters WHERE ID=? 00000657 247.66932678 [48852] 29432 DB lock finished, took 1262. 00000658 247.66947937 [48852] 29432 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00000659 247.66958618 [48852] 29432 DB lock finished, took 121. 00000660 247.67034912 [48852] 29432 DB open SQL: SELECT Songs.* 00000661 247.67034912 [48852] FROM Songs 00000662 247.67034912 [48852] WHERE Songs.id=361311 AND (Songs.SongPath like '%\\lowlander04\Multimedia\Family Videos\%') AND NOT (Songs.SongPath like '%Plex%') 00000663 247.67042542 [48852] OpenQuery - Preparing query SELECT Songs.* 00000664 247.67042542 [48852] FROM Songs 00000665 247.67042542 [48852] WHERE Songs.id=361311 AND (Songs.SongPath like '%\\lowlander04\Multimedia\Family Videos\%') AND NOT (Songs.SongPath like '%Plex%') 00000666 247.67102051 [48852] 29432 DB lock finished, took 5818. 00000667 247.73176575 [48852] PrepareDockedVideo: Begin 00000668 247.73342896 [48852] PrepareDockedVideo: Switching=false IsStartingPlayback=false WasManuallyChanged=false 00000669 247.73399353 [48852] PrepareDockedVideo: Reduced window or audio 00000670 247.73457336 [48852] PrepareDockedVideo: Audio 00000671 247.73513794 [48852] PrepareDockedVideo: End 00000672 247.77305603 [48852] MM4 [49844] TImagePlus.Paint: start 00000673 247.77464294 [48852] MM4 [49844] TStretcher.PerformStretch: Threads[11], source[600, 545], target[352,319] 00000674 247.77467346 [48852] BQ: Added new task. Currently 1 tasks in queue. 00000675 247.77468872 [48852] BQ: Starting a new task. 00000676 247.77471924 [48852] BQ: There are threads waiting, resume one. 00000677 247.77474976 [48852] BQ: Added new task. Currently 2 tasks in queue. 00000678 247.77476501 [48852] BQ: Starting a new task. 00000679 247.77479553 [48852] BQ: There are threads waiting, resume one. 00000680 247.77484131 [48852] BQ: Added new task. Currently 2 tasks in queue. 00000681 247.77487183 [48852] BQ: Starting a new task. 00000682 247.77490234 [48852] BQ: There are threads waiting, resume one. 00000683 247.77491760 [48852] BQ: Added new task. Currently 2 tasks in queue. 00000684 247.77494812 [48852] BQ: Starting a new task. 00000685 247.77497864 [48852] BQ: There are threads waiting, resume one. 00000686 247.77500916 [48852] BQ: Added new task. Currently 2 tasks in queue. 00000687 247.77502441 [48852] BQ: Starting a new task. 00000688 247.77505493 [48852] BQ: There are threads waiting, resume one. 00000689 247.77508545 [48852] BQ: Added new task. Currently 2 tasks in queue. 00000690 247.77510071 [48852] BQ: Starting a new task. 00000691 247.77516174 [48852] BQ: Currently running 6 threads of 8 00000692 247.77523804 [48852] BQ: Starting a new thread. 00000693 247.81887817 [48852] TIndyHTTP.GetResponseContent finished: URL: http://lyrics.wikia.com/wiki/Bruce_Cockburn:Pacing_The_Cage, ResponseContent.Size: 130309, ResponseCode: 200 00000694 247.81985474 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 7, All: 49 00000695 247.82530212 [48852] BQ: Added new task. Currently 2 tasks in queue. 00000696 247.82533264 [48852] BQ: Starting a new task. 00000697 247.82537842 [48852] BQ: There are threads waiting, resume one. 00000698 247.82540894 [48852] BQ: Added new task. Currently 1 tasks in queue. 00000699 247.82543945 [48852] BQ: Starting a new task. 00000700 247.82545471 [48852] BQ: There are threads waiting, resume one. 00000701 247.82548523 [48852] BQ: Added new task. Currently 1 tasks in queue. 00000702 247.82551575 [48852] BQ: Starting a new task. 00000703 247.82553101 [48852] BQ: There are threads waiting, resume one. 00000704 247.82556152 [48852] BQ: Added new task. Currently 1 tasks in queue. 00000705 247.82560730 [48852] BQ: Starting a new task. 00000706 247.82563782 [48852] BQ: There are threads waiting, resume one. 00000707 247.82574463 [48852] MM4 [49844] TStretcher.PerformStretch: Finished 00000708 247.82623291 [48852] MM4 [49844] TImagePlus.Paint: finished 00000709 247.82766724 [48852] Thread 'BackgroundQueue' has started 7116 00000710 247.85612488 [48852] 49844 DB open SQL: SELECT ID, Name, View FROM Views ORDER BY ID 00000711 247.85627747 [48852] 49844 DB lock finished, took 1261. 00000712 247.88899231 [48852] 49844 DB open SQL: SELECT * FROM Filters ORDER BY Pos 00000713 247.88925171 [48852] 49844 DB lock finished, took 2293. 00000714 247.90844727 [48852] lyricsSearch.js: LoadedWebPage 00000715 247.90855408 [48852] lyricsSearch.js: rSuccessLyricWikia 00000716 247.91528320 [48852] lyricsSearch.js: whatNext result 00000717 247.91595459 [48852] DB: BEGIN EXCLUSIVE transaction 00000718 247.91622925 [48852] 42792 DB prepare SQL: UPDATE Songs SET SongPath=?,Artist=?,IdAlbum=?,Album=?,AlbumArtist=?,SongTitle=?,Genre=?,Year=?,IDMedia=?,SongLength=?,PlaybackPos=?,StartTime=?,StopTime=?,SkipCount=?,TrackType=?,VideoHeight=?,VideoWidth=?,FrameRate=?,TrackNumber=?, EpisodeNumber=?, SeasonNumber=?, Actors=?, Producer=?, BitRate=?,FileLength=?,Seekable=?,SamplingFrequency=?,Stereo=?,VBR=?,BPM=?,Author=?,Rating=?,AudioCDTrack=?,FileModified=?,MaxSample=?,NormalizeTrack=?,NormalizeAlbum=?,DateAdded=?,LastTimePlayed=?,PlayCounter=?,Custom1=?,Custom2=?,Custom3=?,Custom4=?,Custom5=?,SignType=?,SignPart1=?,SignPart2=?,SignPart3=?,SignPart4=?,Copyright=?,Publisher=?,Encoder=?,Lyricist=?,Conductor=?,InvolvedPeople=?,OrigTitle=?,OrigArtist=?,OrigLyricist=?, ParentalRating=?,GroupDesc=?,SubTitle=?,ISRC=?,InitialKey=?,Language=?,OrigYear=?,Tempo=?,Mood=?,Occasion=?,Quality=?,Lyrics=?,Comment=?,DiscNumber=?,PreGap=?,PostGap=?,TotalSamples=?,GaplessBytes=?,TrackModified=?,ContainerType=?,StreamCount=?,StreamInfo=? WHERE ID=? 00000719 247.91828918 [48852] 42792 DB query prepare finished, took 19629. 00000720 247.91836548 [48852] 42792 DB prepare SQL: SELECT ID,Album FROM Albums WHERE Album=? AND Artist=? 00000721 247.91848755 [48852] 42792 DB query prepare finished, took 440. 00000722 247.91856384 [48852] 42792 DB open SQL: SELECT ID,Album FROM Albums WHERE Album=? AND Artist=? 00000723 247.91871643 [48852] 42792 DB lock finished, took 854. 00000724 247.91886902 [48852] 42792 DB prepare SQL: SELECT PreviewStartTime, PreviewLength, CacheName, PreviewName, Copyright, Encoder, ISRC, InitialKey, Language, OrigLyricist, ParentalRating,PreGap, PostGap, TotalSamples, GaplessBytes, SignType, SignPart1, SignPart2, SignPart3, SignPart4, ContainerType, StreamCount, StreamInfo FROM Songs WHERE ID=? 00000725 247.91902161 [48852] 42792 DB query prepare finished, took 1010. 00000726 247.91909790 [48852] 42792 DB open SQL: SELECT PreviewStartTime, PreviewLength, CacheName, PreviewName, Copyright, Encoder, ISRC, InitialKey, Language, OrigLyricist, ParentalRating,PreGap, PostGap, TotalSamples, GaplessBytes, SignType, SignPart1, SignPart2, SignPart3, SignPart4, ContainerType, StreamCount, StreamInfo FROM Songs WHERE ID=? 00000727 247.91917419 [48852] 42792 DB lock finished, took 169. 00000728 247.91935730 [48852] 42792 DB exec SQL: UPDATE Songs SET SongPath=?,Artist=?,IdAlbum=?,Album=?,AlbumArtist=?,SongTitle=?,Genre=?,Year=?,IDMedia=?,SongLength=?,PlaybackPos=?,StartTime=?,StopTime=?,SkipCount=?,TrackType=?,VideoHeight=?,VideoWidth=?,FrameRate=?,TrackNumber=?, EpisodeNumber=?, SeasonNumber=?, Actors=?, Producer=?, BitRate=?,FileLength=?,Seekable=?,SamplingFrequency=?,Stereo=?,VBR=?,BPM=?,Author=?,Rating=?,AudioCDTrack=?,FileModified=?,MaxSample=?,NormalizeTrack=?,NormalizeAlbum=?,DateAdded=?,LastTimePlayed=?,PlayCounter=?,Custom1=?,Custom2=?,Custom3=?,Custom4=?,Custom5=?,SignType=?,SignPart1=?,SignPart2=?,SignPart3=?,SignPart4=?,Copyright=?,Publisher=?,Encoder=?,Lyricist=?,Conductor=?,InvolvedPeople=?,OrigTitle=?,OrigArtist=?,OrigLyricist=?, ParentalRating=?,GroupDesc=?,SubTitle=?,ISRC=?,InitialKey=?,Language=?,OrigYear=?,Tempo=?,Mood=?,Occasion=?,Quality=?,Lyrics=?,Comment=?,DiscNumber=?,PreGap=?,PostGap=?,TotalSamples=?,GaplessBytes=?,TrackModified=?,ContainerType=?,StreamCount=?,StreamInfo=? WHERE ID=? 00000729 247.91950989 [48852] 42792 DB lock successful. 00000730 247.92703247 [48852] 42792 DB lock finished, took 75567. 00000731 247.92706299 [48852] 42792 DB prepare SQL: SELECT ID,Artist FROM Artists WHERE Artist=? 00000732 247.92712402 [48852] 42792 DB query prepare finished, took 252. 00000733 247.92713928 [48852] 42792 DB open SQL: SELECT ID,Artist FROM Artists WHERE Artist=? 00000734 247.92759705 [48852] 42792 DB lock finished, took 4200. 00000735 247.92765808 [48852] 42792 DB prepare SQL: SELECT null FROM ArtistsSongs WHERE PersonType = ? AND IDArtist=? AND IDSong=? AND TrackType = ? 00000736 247.92770386 [48852] 42792 DB query prepare finished, took 264. 00000737 247.92773438 [48852] 42792 DB open SQL: SELECT null FROM ArtistsSongs WHERE PersonType = ? AND IDArtist=? AND IDSong=? AND TrackType = ? 00000738 247.92977905 [48852] 42792 DB lock finished, took 19888. 00000739 247.92980957 [48852] 42792 DB open SQL: SELECT IDGenre FROM Genres WHERE GenreName='Folk' 00000740 247.92985535 [48852] OpenQuery - Preparing query SELECT IDGenre FROM Genres WHERE GenreName='Folk' 00000741 247.93011475 [48852] 42792 DB lock finished, took 2612. 00000742 247.93013000 [48852] 42792 DB open SQL: SELECT IDGenre FROM Genres WHERE GenreName='Live' 00000743 247.93019104 [48852] OpenQuery - Preparing query SELECT IDGenre FROM Genres WHERE GenreName='Live' 00000744 247.93023682 [48852] 42792 DB lock finished, took 548. 00000745 247.93026733 [48852] 42792 DB prepare SQL: SELECT null FROM GenresSongs WHERE IDGenre = ? AND IDSong = ? AND TrackType=? 00000746 247.93031311 [48852] 42792 DB query prepare finished, took 217. 00000747 247.93034363 [48852] 42792 DB open SQL: SELECT null FROM GenresSongs WHERE IDGenre = ? AND IDSong = ? AND TrackType=? 00000748 247.93449402 [48852] 42792 DB lock finished, took 40911. 00000749 247.93450928 [48852] 42792 DB open SQL: SELECT null FROM GenresSongs WHERE IDGenre = ? AND IDSong = ? AND TrackType=? 00000750 247.94009399 [48852] 42792 DB lock finished, took 55062. 00000751 247.94012451 [48852] 42792 DB exec SQL: DELETE FROM ArtistsSongs WHERE IDSong=361311 AND IDArtist NOT IN (16820) 00000752 247.94013977 [48852] 42792 DB lock successful. 00000753 247.94073486 [48852] 42792 DB lock finished, took 5290. 00000754 247.94076538 [48852] 42792 DB exec SQL: DELETE FROM GenresSongs WHERE IDSong=361311 AND IDGenre NOT IN (80,100073) 00000755 247.94078064 [48852] 42792 DB lock successful. 00000756 247.94129944 [48852] 42792 DB lock finished, took 4697. 00000757 247.94132996 [48852] TCoverList.SaveForSongId: 361311 00000758 247.94134521 [48852] 42792 DB exec SQL: DELETE FROM Covers WHERE IDSong = 361311 00000759 247.94137573 [48852] 42792 DB lock successful. 00000760 247.94149780 [48852] 42792 DB lock finished, took 953. 00000761 247.94155884 [48852] 42792 DB exec SQL: UPDATE Songs SET ArtworkModified=43497.769393542 WHERE Id=361311 00000762 247.94157410 [48852] 42792 DB lock successful. 00000763 247.94175720 [48852] 42792 DB lock finished, took 1505. 00000764 247.94181824 [48852] MM4 [42792] Cleaning image cache for song id 361311 00000765 247.94204712 [48852] 42792 DB open SQL: SELECT IDAlbum FROM Songs WHERE ID = 361311 00000766 247.94209290 [48852] OpenQuery - Preparing query SELECT IDAlbum FROM Songs WHERE ID = 361311 00000767 247.94216919 [48852] 42792 DB lock finished, took 545. 00000768 247.95660400 [48852] MM4 [42792] Cleaning image cache for song id 361311 finished 00000769 247.95663452 [48852] 42792 DB exec SQL: INSERT INTO Covers (IDSong, CoverOrder, CoverPath, CoverStorage, CoverDescription, CoverType, PictureType) VALUES (361311, 0, '', 0, '', 3, 'image/jpeg') 00000770 247.95666504 [48852] 42792 DB lock successful. 00000771 247.95681763 [48852] 42792 DB lock finished, took 1081. 00000772 247.95683289 [48852] Auto-Organizer : Begin checking track D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00000773 247.95689392 [48852] Auto-Organizer : Checking rule:Collections:Muziek; \\lowlander03\Multimedia\$if(=Audiobook,Audiobooks,Music)\\$Left(,50)\[] $Left(,50)\$If(,-,). $Left(,50) - $Left(,50)$if(<Type><>Audiobook,$if(<Rating>=0, (bad copy$),)) for filter 00000774 247.95690918 [48852] 42792 DB open SQL: SELECT Songs.ID FROM Songs WHERE Songs.ID=? AND ( (Songs.SongPath like '%\\lowlander03\Multimedia\Music\%') ) 00000775 247.95697021 [48852] 42792 DB lock finished, took 103. 00000776 247.95698547 [48852] Auto-Organizer : Track doesn't satisfy rule:Collections:Muziek; \\lowlander03\Multimedia\$if(<Type>=Audiobook,Audiobooks,Music)\<Album Artist:1>\$Left(<Album Artist>,50)\[<Year>] $Left(<Album>,50)\$If(<Disc#>,<Disc#:2>-,)<Track#:2>. $Left(<Artist>,50) - $Left(<Title>,50)$if(<Type><>Audiobook,$if(<Rating>=0, (bad copy$),)) 00000777 247.95704651 [48852] 42792 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6218 00000778 247.95706177 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6218 00000779 247.95713806 [48852] 42792 DB lock finished, took 710. 00000780 247.95716858 [48852] Auto-Organizer : Checking rule:Playlists:Global National; \\lowlander04\Multimedia\Podcasts\Global National\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - $Replace(<Title>,:,) for playlist 00000781 247.95719910 [48852] 42792 DB open SQL: SELECT Songs.Id AS SongID 00000782 247.95719910 [48852] FROM Songs WHERE Songs.ID = ? AND (Songs.Album like '%Global National%') AND Songs.TrackType in (1,7) 00000783 247.95724487 [48852] 42792 DB lock finished, took 72. 00000784 247.95727539 [48852] 42792 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6218 00000785 247.95730591 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6218 00000786 247.95735168 [48852] 42792 DB lock finished, took 430. 00000787 247.95738220 [48852] Auto-Organizer : Track doesn't satisfy rule:Playlists:Global National; \\lowlander04\Multimedia\Podcasts\Global National\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - $Replace(<Title>,:,) 00000788 247.95739746 [48852] 42792 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6220 00000789 247.95742798 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6220 00000790 247.95750427 [48852] 42792 DB lock finished, took 510. 00000791 247.95753479 [48852] Auto-Organizer : Checking rule:Playlists:NOS Journaal; \\lowlander04\Multimedia\Podcasts\NOS Journaal\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - Journaal van $Mid(<Title>,21) for playlist 00000792 247.95755005 [48852] 42792 DB open SQL: SELECT Songs.Id AS SongID 00000793 247.95755005 [48852] FROM Songs WHERE Songs.ID = ? AND (Songs.Album like '%NOS Journaal%') AND Songs.TrackType in (1,7) 00000794 247.95761108 [48852] 42792 DB lock finished, took 69. 00000795 247.95762634 [48852] 42792 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6220 00000796 247.95765686 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6220 00000797 247.95770264 [48852] 42792 DB lock finished, took 422. 00000798 247.95773315 [48852] Auto-Organizer : Track doesn't satisfy rule:Playlists:NOS Journaal; \\lowlander04\Multimedia\Podcasts\NOS Journaal\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - Journaal van $Mid(<Title>,21) 00000799 247.95776367 [48852] 42792 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6221 00000800 247.95777893 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6221 00000801 247.95783997 [48852] 42792 DB lock finished, took 415. 00000802 247.95785522 [48852] Auto-Organizer : Checking rule:Playlists:NOS Juegdjournaal; \\lowlander04\Multimedia\Podcasts\NOS Jeugdjournaal\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - Jeugdjournaal van $Mid(<Title>,19,10) $Right(<Title>,5) for playlist 00000803 247.95788574 [48852] 42792 DB open SQL: SELECT Songs.Id AS SongID 00000804 247.95788574 [48852] FROM Songs WHERE Songs.ID = ? AND (Songs.Album like '%NOS Jeugdjournaal%') AND Songs.TrackType in (1,7) 00000805 247.95794678 [48852] 42792 DB lock finished, took 63. 00000806 247.95796204 [48852] 42792 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6221 00000807 247.95799255 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6221 00000808 247.95803833 [48852] 42792 DB lock finished, took 425. 00000809 247.95806885 [48852] Auto-Organizer : Track doesn't satisfy rule:Playlists:NOS Juegdjournaal; \\lowlander04\Multimedia\Podcasts\NOS Jeugdjournaal\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - Jeugdjournaal van $Mid(<Title>,19,10) $Right(<Title>,5) 00000810 247.95809937 [48852] 42792 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6222 00000811 247.95811462 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6222 00000812 247.95817566 [48852] 42792 DB lock finished, took 420. 00000813 247.95819092 [48852] Auto-Organizer : Checking rule:Playlists:EenVandaag; \\lowlander04\Multimedia\Podcasts\EenVandaag\<Podcast> - s$Mid(<Title>,18)$Mid(<Title>,15,2)e$Right(<Date>,2) - <Title> for playlist 00000814 247.95825195 [48852] 42792 DB open SQL: SELECT Songs.Id AS SongID 00000815 247.95825195 [48852] FROM Songs WHERE Songs.ID = ? AND (Songs.Album like '%EénVandaag%') AND Songs.TrackType in (1,7) 00000816 247.95834351 [48852] 42792 DB lock finished, took 65. 00000817 247.95845032 [48852] 42792 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6222 00000818 247.95848083 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6222 00000819 247.95852661 [48852] 42792 DB lock finished, took 1088. 00000820 247.95855713 [48852] Auto-Organizer : Track doesn't satisfy rule:Playlists:EenVandaag; \\lowlander04\Multimedia\Podcasts\EenVandaag\<Podcast> - s$Mid(<Title>,18)$Mid(<Title>,15,2)e$Right(<Date>,2) - <Title> 00000821 247.95857239 [48852] 42792 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6223 00000822 247.95863342 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6223 00000823 247.95864868 [48852] 42792 DB lock finished, took 455. 00000824 247.95870972 [48852] Auto-Organizer : Checking rule:Playlists:Nieuwsuur; \\lowlander04\Multimedia\Podcasts\Nieuwsuur\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - Nieuwsuur van $Mid(<Title>,11,10) for playlist 00000825 247.95874023 [48852] 42792 DB open SQL: SELECT Songs.Id AS SongID 00000826 247.95874023 [48852] FROM Songs WHERE Songs.ID = ? AND (Songs.Album like '%Nieuwsuur%') AND Songs.TrackType in (1,7) 00000827 247.95875549 [48852] 42792 DB lock finished, took 76. 00000828 247.95878601 [48852] 42792 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6223 00000829 247.95881653 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6223 00000830 247.95886230 [48852] 42792 DB lock finished, took 442. 00000831 247.95890808 [48852] Auto-Organizer : Track doesn't satisfy rule:Playlists:Nieuwsuur; \\lowlander04\Multimedia\Podcasts\Nieuwsuur\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - Nieuwsuur van $Mid(<Title>,11,10) 00000832 247.95893860 [48852] 42792 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6224 00000833 247.95896912 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6224 00000834 247.95901489 [48852] 42792 DB lock finished, took 436. 00000835 247.95904541 [48852] Auto-Organizer : Checking rule:Playlists:Tagesschau; \\lowlander04\Multimedia\Podcasts\Tagesschau\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - Tagesschau von $Left(<Title>,10) for playlist 00000836 247.95906067 [48852] 42792 DB open SQL: SELECT Songs.Id AS SongID 00000837 247.95906067 [48852] FROM Songs WHERE Songs.ID = ? AND (Songs.Album like '%Tagesschau%') AND Songs.TrackType in (1,7) 00000838 247.95909119 [48852] 42792 DB lock finished, took 71. 00000839 247.95913696 [48852] 42792 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6224 00000840 247.95916748 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6224 00000841 247.95919800 [48852] 42792 DB lock finished, took 429. 00000842 247.95924377 [48852] Auto-Organizer : Track doesn't satisfy rule:Playlists:Tagesschau; \\lowlander04\Multimedia\Podcasts\Tagesschau\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - Tagesschau von $Left(<Title>,10) 00000843 247.95927429 [48852] 42792 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6225 00000844 247.95928955 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6225 00000845 247.95935059 [48852] 42792 DB lock finished, took 430. 00000846 247.95936584 [48852] Auto-Organizer : Checking rule:Playlists:Talking Cars; \\lowlander04\Multimedia\Podcasts\Talking Cars\<Podcast> - s01e$Trim($Replace($Replace($Mid(<Title>,2,4),-),#)) - <Title> for playlist 00000847 247.95939636 [48852] 42792 DB open SQL: SELECT Songs.Id AS SongID 00000848 247.95939636 [48852] FROM Songs WHERE Songs.ID = ? AND (Songs.Album like '%Talking Cars%') AND Songs.TrackType in (1,7) 00000849 247.95944214 [48852] 42792 DB lock finished, took 67. 00000850 247.95947266 [48852] 42792 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6225 00000851 247.95950317 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6225 00000852 247.95954895 [48852] 42792 DB lock finished, took 423. 00000853 247.95957947 [48852] Auto-Organizer : Track doesn't satisfy rule:Playlists:Talking Cars; \\lowlander04\Multimedia\Podcasts\Talking Cars\<Podcast> - s01e$Trim($Replace($Replace($Mid(<Title>,2,4),-),#)) - <Title> 00000854 247.95960999 [48852] 42792 DB prepare SQL: SELECT Count(*) FROM PathProcessing 00000855 247.95965576 [48852] 42792 DB query prepare finished, took 168. 00000856 247.95968628 [48852] 42792 DB open SQL: SELECT Count(*) FROM PathProcessing 00000857 247.95973206 [48852] 42792 DB lock finished, took 126. 00000858 247.95976257 [48852] 42792 DB prepare SQL: SELECT * FROM Artists WHERE Artist=? 00000859 247.95980835 [48852] 42792 DB query prepare finished, took 324. 00000860 247.95985413 [48852] 42792 DB open SQL: SELECT * FROM Artists WHERE Artist=? 00000861 247.95991516 [48852] 42792 DB lock finished, took 336. 00000862 247.95996094 [48852] TBackgroundTagger.UpdateTags, Count = 1 00000863 247.95999146 [48852] TBackgroundTagger.UpdateTags: Got BTLockCS 00000864 247.96003723 [48852] Tagging: New thread starting 00000865 247.96006775 [48852] Tagging: Queuing finished 00000866 247.99162292 [48852] TGenThread.Create: ThreadName: _DoTag , Running Threads: Internal: 8, All: 47 00000867 247.99810791 [48852] Events: Destroying TScriptExec: D:\Software\MediaMonkey\Scripts\lyricsSearch.js 00000868 247.99845886 [48852] Going 'SearchLyricsOnBackgroud_Var'to make final callback 42792 00000869 247.99885559 [48852] MM4 [49844] TLyricsScroller.createOverlay: rows: 36 00000870 248.00076294 [48852] Thread '_DoTag' has started 27260 00000871 248.00086975 [48852] Tagging: Track will be tagged now: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac, AlbumArtCount=1 00000872 248.00094604 [48852] PrepareForTagging: called 00000873 248.00099182 [48852] PrepareForTagging: Our track is playing 00000874 248.00547791 [48852] MM4 [49844] TLyricsScroller.createOverlay: finished 00000875 248.00550842 [48852] MM4 [49844] TLyricsScroller.createOverlay: rows: 36 00000876 248.02055359 [48852] MM4 [49844] TLyricsScroller.createOverlay: finished 00000877 248.02116394 [48852] MM4 [49844] TImagePlus.Paint: start 00000878 248.02140808 [48852] MM4 [49844] TImagePlus.Paint: finished 00000879 248.02851868 [48852] IntPlay: Play thread Finishing Playback 00000880 248.02864075 [48852] Going to execute format plug-in destructor. 00000881 248.02870178 [48852] FLAC: FORMAT_DecodeClose(). 00000882 248.02934265 [48852] IntPlay: Play thread Exit 00000883 248.02941895 [48852] Going 'PlayThreadProc'to make final callback 47288 00000884 248.02954102 [48852] Thread 'PlayThreadProc'has finished 47288 00000885 248.04858398 [48852] PrepareForTagging: Track is stopped for tagging 00000886 248.04910278 [48852] FH.WriteFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00000887 248.04917908 [48852] f_flac: FORMAT_OpenFile 00000888 248.05027771 [48852] FH.WriteFileInfo: openned 00000889 248.05032349 [48852] f_flac: FORMAT_SetInteger 00000890 248.05043030 [48852] f_flac: FORMAT_SetInteger 00000891 248.05047607 [48852] f_flac: FORMAT_SetInteger 00000892 248.05056763 [48852] f_flac: FORMAT_SetInteger 00000893 248.05061340 [48852] f_flac: FORMAT_SetDouble 00000894 248.05065918 [48852] f_flac: FORMAT_SetInteger 00000895 248.05072021 [48852] f_flac: FORMAT_SetInteger 00000896 248.05079651 [48852] f_flac: FORMAT_SetInteger 00000897 248.05084229 [48852] f_flac: FORMAT_SetInteger 00000898 248.05088806 [48852] f_flac: FORMAT_SetString 00000899 248.05094910 [48852] f_flac: FORMAT_SetString 00000900 248.05102539 [48852] f_flac: FORMAT_SetString 00000901 248.05107117 [48852] f_flac: FORMAT_SetString 00000902 248.05111694 [48852] f_flac: FORMAT_SetString 00000903 248.05117798 [48852] f_flac: FORMAT_SetString 00000904 248.05122375 [48852] f_flac: FORMAT_SetString 00000905 248.05130005 [48852] f_flac: FORMAT_SetString 00000906 248.05136108 [48852] f_flac: FORMAT_SetString 00000907 248.05140686 [48852] f_flac: FORMAT_SetString 00000908 248.05145264 [48852] f_flac: FORMAT_SetString 00000909 248.05151367 [48852] f_flac: FORMAT_SetString 00000910 248.05158997 [48852] f_flac: FORMAT_SetString 00000911 248.05163574 [48852] f_flac: FORMAT_SetString 00000912 248.05168152 [48852] f_flac: FORMAT_SetString 00000913 248.05174255 [48852] f_flac: FORMAT_SetString 00000914 248.05178833 [48852] f_flac: FORMAT_SetString 00000915 248.05186462 [48852] f_flac: FORMAT_SetString 00000916 248.05191040 [48852] f_flac: FORMAT_SetString 00000917 248.05197144 [48852] f_flac: FORMAT_SetString 00000918 248.05201721 [48852] f_flac: FORMAT_SetString 00000919 248.05206299 [48852] f_flac: FORMAT_SetString 00000920 248.05216980 [48852] f_flac: FORMAT_SetString 00000921 248.05223083 [48852] f_flac: FORMAT_SetString 00000922 248.05230713 [48852] f_flac: FORMAT_SetString 00000923 248.05235291 [48852] f_flac: FORMAT_SetString 00000924 248.05242920 [48852] f_flac: FORMAT_SetString 00000925 248.05247498 [48852] f_flac: FORMAT_SetString 00000926 248.05253601 [48852] f_flac: FORMAT_SetString 00000927 248.05258179 [48852] f_flac: FORMAT_SetString 00000928 248.05262756 [48852] f_flac: FORMAT_SetString 00000929 248.05268860 [48852] f_flac: FORMAT_SetString 00000930 248.05276489 [48852] f_flac: FORMAT_SetDouble 00000931 248.05281067 [48852] f_flac: FORMAT_SetDouble 00000932 248.05285645 [48852] f_flac: FORMAT_SetDouble 00000933 248.05291748 [48852] FH.WriteFileInfo: going to tag artworks 00000934 248.05299377 [48852] FH.WriteFileInfo: artwork count = 1 00000935 248.05303955 [48852] f_flac: FORMAT_SetInteger 00000936 248.05311584 [48852] f_flac: FORMAT_SetBinary 00000937 248.05319214 [48852] FH.WriteFileInfo: artwork tagging finished 00000938 248.05325317 [48852] f_flac: FORMAT_UpdateTag 00000939 248.05337524 [48852] flacParser: UpdateTag 00000940 248.05342102 [48852] flacParser: ConvertMetadataToBlock BEGIN 00000941 248.05435181 [48852] flacParser: ConvertMetadataToBlock END 00000942 248.05442810 [48852] flacParser: ConvertAAToBlocks BEGIN 00000943 248.05453491 [48852] flacParser: ConvertAAToBlocks END 00000944 248.05461121 [48852] flacParser: AddPaddingBlock 00000945 248.05667114 [48852] Thread 'SearchLyricsOnBackgroud_Var'has finished 42792 00000946 248.06182861 [48852] FH.WriteFileInfo: updated 00000947 248.06187439 [48852] f_flac: FORMAT_CloseFile 00000948 248.06248474 [48852] 27260 DB exec SQL: UPDATE Songs SET FileLength=27360830, TrackModified=43497.769394931,FileModified=43497.769394931 WHERE ID=361311 00000949 248.06256104 [48852] 27260 DB lock successful. 00000950 248.06318665 [48852] 27260 DB lock finished, took 5120. 00000951 248.06413269 [48852] RestoreFromTagging starting. 00000952 248.06433105 [48852] RestoreFromTagging starting. 00000953 248.06437683 [48852] RestoreFromTagging going to proceeed. 00000954 248.06440735 [48852] Player: Song is not cached, try to play the original file 00000955 248.06466675 [48852] Decoder: CreateDecoder() started 00000956 248.06469727 [48852] Going to execute format plug-in constructor. 00000957 248.06471252 [48852] FLAC: FORMAT_DecodeInit(). 00000958 248.06474304 [48852] FLAC: Going to create stream decoder. 00000959 248.06477356 [48852] FLAC: Stream decoder created. 00000960 248.06489563 [48852] FLAC: Calling FLAC__stream_decoder_init_stream(). 00000961 248.06492615 [48852] FLAC: Calling FLAC__stream_decoder_process_until_end_of_metadata(). 00000962 248.06497192 [48852] FLAC: StreamDecoderMetadataCallback. 00000963 248.06520081 [48852] FLAC: FORMAT_DecodeInit() finished. 00000964 248.06523132 [48852] Format plug-in constructor finished. 00000965 248.06526184 [48852] Decoder: CreateDecoder() finished successfuly 00000966 248.09069824 [48852] TGenThread.Create: ThreadName: PlayThreadProc , Running Threads: Internal: 8, All: 46 00000967 248.09968567 [48852] Thread 'PlayThreadProc' has started 10752 00000968 248.09979248 [48852] IntPlay: Play thread Enter 00000969 248.09991455 [48852] IntPlay: Play thread Open Output 00000970 248.09999084 [48852] IntPlay: Play thread Set Stream Info 00000971 248.13386536 [48852] IntPlay: Play thread SRate set 00000972 248.13394165 [48852] IntPlay: Play thread Set Volume 00000973 248.13398743 [48852] IntPlay: Play thread Main loop start 00000974 248.13401794 [48852] Going to execute format plug-in seek method. 00000975 248.13406372 [48852] SynchronizingAfterTagging starting 00000976 248.13414001 [48852] RestoreFromTagging finished. 00000977 248.13427734 [48852] Tagging: Track was tagged: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00000978 248.13436890 [48852] Tagging: Thread finished 00000979 248.13444519 [48852] Going '_DoTag'to make final callback 27260 00000980 248.13455200 [48852] Thread '_DoTag'has finished 27260 00000981 248.25750732 [48852] Win7Tools - Thumbnail - add rating stars 00000982 248.25965881 [48852] Win7Tools - Thumbnail - add rating stars 00000983 248.26034546 [48852] MM4 [49844] TImagePlus.Paint: start 00000984 248.26091003 [48852] MM4 [49844] TImagePlus.Paint: finished 00000985 248.30993652 [48852] Win7Tools - Thumbnail - add rating stars 00000986 248.31205750 [48852] Win7Tools - Thumbnail - add rating stars 00000987 248.31306458 [48852] MM4 [49844] TImagePlus.Paint: start 00000988 248.31324768 [48852] MM4 [49844] TImagePlus.Paint: finished 00000989 248.33787537 [48852] SynchronizingAfterTagging - buffer match found 00000990 248.33789063 [48852] SynchronizingAfterTagging finished 00000991 248.35028076 [48852] Win7Tools - Thumbnail - add rating stars 00000992 248.35238647 [48852] Win7Tools - Thumbnail - add rating stars 00000993 248.35336304 [48852] MM4 [49844] TImagePlus.Paint: start 00000994 248.35353088 [48852] MM4 [49844] TImagePlus.Paint: finished 00000995 248.68150330 [48852] BQ: Added new task. Currently 1 tasks in queue. 00000996 248.68290710 [48852] BQ: Starting a new task. 00000997 248.68380737 [48852] BQ: There are threads waiting, resume one. 00000998 248.68469238 [48852] 11300 DB open SQL: SELECT Songs.ID FROM Songs WHERE ( Songs.TrackType in (4) ) LIMIT 1 00000999 248.68554688 [48852] 11300 DB lock finished, took 710. 00001000 249.72946167 [48852] TGenThread.Create: ThreadName: _ManageTransactions , Running Threads: Internal: 8, All: 46 00001001 249.73735046 [48852] Thread '_ManageTransactions' has started 50784 00001002 249.73744202 [48852] Going '_ManageTransactions'to make final callback 50784 00001003 249.73754883 [48852] Thread '_ManageTransactions'has finished 50784 00001004 250.83871460 [48852] Going 'BackgroundQueue'to make final callback 13476 00001005 250.83872986 [48852] Going 'BackgroundQueue'to make final callback 50772 00001006 250.83876038 [48852] Going 'BackgroundQueue'to make final callback 14176 00001007 250.83879089 [48852] Going 'BackgroundQueue'to make final callback 53124 00001008 250.83886719 [48852] Going 'BackgroundQueue'to make final callback 7116 00001009 250.83888245 [48852] DB: Deleting prepared query: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00001010 250.83894348 [48852] Thread 'BackgroundQueue'has finished 50772 00001011 250.83895874 [48852] Thread 'BackgroundQueue'has finished 14176 00001012 250.83901978 [48852] Thread 'BackgroundQueue'has finished 53124 00001013 250.83903503 [48852] Thread 'BackgroundQueue'has finished 7116 00001014 250.83909607 [48852] Thread 'BackgroundQueue'has finished 13476 00001015 250.85890198 [48852] Going 'BackgroundQueue'to make final callback 48960 00001016 250.85896301 [48852] Thread 'BackgroundQueue'has finished 48960 00001017 251.37973022 [48852] Win7Tools - Thumbnail - add rating stars 00001018 251.69882202 [48852] Going 'BackgroundQueue'to make final callback 11300 00001019 251.69897461 [48852] Thread 'BackgroundQueue'has finished 11300 00001020 251.73115540 [48852] TGenThread.Create: ThreadName: _ManageTransactions , Running Threads: Internal: 2, All: 41 00001021 251.74031067 [48852] Thread '_ManageTransactions' has started 4416 00001022 251.74041748 [48852] Going '_ManageTransactions'to make final callback 4416 00001023 251.74052429 [48852] Thread '_ManageTransactions'has finished 4416 00001024 253.72894287 [48852] TGenThread.Create: ThreadName: _ManageTransactions , Running Threads: Internal: 1, All: 41 00001025 253.74046326 [48852] Thread '_ManageTransactions' has started 49412 00001026 253.74053955 [48852] Going '_ManageTransactions'to make final callback 49412 00001027 253.74064636 [48852] Thread '_ManageTransactions'has finished 49412 00001028 254.46504211 [48852] Win7Tools - Thumbnail - add rating stars 00001029 255.72973633 [48852] TGenThread.Create: ThreadName: _ManageTransactions , Running Threads: Internal: 1, All: 39 00001030 255.73857117 [48852] Thread '_ManageTransactions' has started 36328 00001031 255.73867798 [48852] Going '_ManageTransactions'to make final callback 36328 00001032 255.73878479 [48852] Thread '_ManageTransactions'has finished 36328 00001033 257.47991943 [48852] Win7Tools - Thumbnail - add rating stars 00001034 257.71853638 [48852] TGenThread.Create: ThreadName: _ManageTransactions , Running Threads: Internal: 1, All: 39 00001035 257.73031616 [48852] Thread '_ManageTransactions' has started 46840 00001036 257.73043823 [48852] Going '_ManageTransactions'to make final callback 46840 00001037 257.73052979 [48852] Thread '_ManageTransactions'has finished 46840 00001038 259.74981689 [48852] TGenThread.Create: ThreadName: _ManageTransactions , Running Threads: Internal: 1, All: 40 00001039 259.75891113 [48852] Thread '_ManageTransactions' has started 50720 00001040 259.75900269 [48852] DB: COMMIT transaction 00001041 259.77166748 [48852] Going '_ManageTransactions'to make final callback 50720 00001042 259.77169800 [48852] Thread '_ManageTransactions'has finished 50720 00001043 260.57025146 [48852] Win7Tools - Thumbnail - add rating stars 00001044 263.68026733 [48852] Win7Tools - Thumbnail - add rating stars 00001045 265.90826416 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 38 00001046 265.91699219 [48852] PostponeComputerSleep: Enabled = 0 00001047 265.92001343 [48852] Thread 'UpdateDriveLetters_Var' has started 8188 00001048 265.92013550 [48852] >UpdateDriveLetters - start< 00001049 265.95819092 [48852] >UpdateDriveLetters - end< 00001050 265.95822144 [48852] Going 'UpdateDriveLetters_Var'to make final callback 8188 00001051 265.95828247 [48852] Thread 'UpdateDriveLetters_Var'has finished 8188 00001052 266.72006226 [48852] Win7Tools - Thumbnail - add rating stars 00001053 269.74975586 [48852] Win7Tools - Thumbnail - add rating stars 00001054 272.83547974 [48852] Win7Tools - Thumbnail - add rating stars 00001055 275.85009766 [48852] Win7Tools - Thumbnail - add rating stars 00001056 278.90994263 [48852] Win7Tools - Thumbnail - add rating stars 00001057 281.96981812 [48852] Win7Tools - Thumbnail - add rating stars 00001058 285.01995850 [48852] Win7Tools - Thumbnail - add rating stars 00001059 288.10061646 [48852] Win7Tools - Thumbnail - add rating stars 00001060 291.15975952 [48852] Win7Tools - Thumbnail - add rating stars 00001061 294.17999268 [48852] Win7Tools - Thumbnail - add rating stars 00001062 295.92504883 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 38 00001063 295.93112183 [48852] PostponeComputerSleep: Enabled = 0 00001064 295.93414307 [48852] Thread 'UpdateDriveLetters_Var' has started 49092 00001065 295.93429565 [48852] >UpdateDriveLetters - start< 00001066 295.94995117 [48852] >UpdateDriveLetters - end< 00001067 295.95001221 [48852] Going 'UpdateDriveLetters_Var'to make final callback 49092 00001068 295.95007324 [48852] Thread 'UpdateDriveLetters_Var'has finished 49092 00001069 297.21987915 [48852] Win7Tools - Thumbnail - add rating stars 00001070 300.25979614 [48852] Win7Tools - Thumbnail - add rating stars 00001071 303.36993408 [48852] Win7Tools - Thumbnail - add rating stars 00001072 306.43002319 [48852] Win7Tools - Thumbnail - add rating stars 00001073 309.18640137 [48852] APPCOMMAND_MEDIA: 18 mapped from VK_MEDIA 00001074 309.34408569 [48852] APPCOMMAND_MEDIA: 18 mapped from VK_MEDIA 00001075 309.47900391 [48852] Win7Tools - Thumbnail - add rating stars 00001076 309.51919556 [48852] APPCOMMAND_MEDIA: 18 mapped from VK_MEDIA 00001077 312.59997559 [48852] Win7Tools - Thumbnail - add rating stars 00001078 315.61990356 [48852] Win7Tools - Thumbnail - add rating stars 00001079 318.72015381 [48852] Win7Tools - Thumbnail - add rating stars 00001080 321.82992554 [48852] Win7Tools - Thumbnail - add rating stars 00001081 324.87496948 [48852] Win7Tools - Thumbnail - add rating stars 00001082 325.92904663 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 37 00001083 325.93511963 [48852] PostponeComputerSleep: Enabled = 0 00001084 325.93789673 [48852] Thread 'UpdateDriveLetters_Var' has started 17896 00001085 325.93798828 [48852] >UpdateDriveLetters - start< 00001086 325.95187378 [48852] >UpdateDriveLetters - end< 00001087 325.95190430 [48852] Going 'UpdateDriveLetters_Var'to make final callback 17896 00001088 325.95193481 [48852] Thread 'UpdateDriveLetters_Var'has finished 17896 00001089 327.97982788 [48852] Win7Tools - Thumbnail - add rating stars 00001090 331.01956177 [48852] Win7Tools - Thumbnail - add rating stars 00001091 334.12072754 [48852] Win7Tools - Thumbnail - add rating stars 00001092 337.16046143 [48852] Win7Tools - Thumbnail - add rating stars 00001093 340.19039917 [48852] Win7Tools - Thumbnail - add rating stars 00001094 343.21005249 [48852] Win7Tools - Thumbnail - add rating stars 00001095 346.31527710 [48852] Win7Tools - Thumbnail - add rating stars 00001096 349.41998291 [48852] Win7Tools - Thumbnail - add rating stars 00001097 352.47961426 [48852] Win7Tools - Thumbnail - add rating stars 00001098 355.59985352 [48852] Win7Tools - Thumbnail - add rating stars 00001099 355.93295288 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 36 00001100 355.93960571 [48852] PostponeComputerSleep: Enabled = 0 00001101 355.94094849 [48852] Thread 'UpdateDriveLetters_Var' has started 44564 00001102 355.94100952 [48852] >UpdateDriveLetters - start< 00001103 355.95498657 [48852] >UpdateDriveLetters - end< 00001104 355.95504761 [48852] Going 'UpdateDriveLetters_Var'to make final callback 44564 00001105 355.95513916 [48852] Thread 'UpdateDriveLetters_Var'has finished 44564 00001106 358.62518311 [48852] Win7Tools - Thumbnail - add rating stars 00001107 361.68984985 [48852] Win7Tools - Thumbnail - add rating stars 00001108 364.79006958 [48852] Win7Tools - Thumbnail - add rating stars 00001109 367.90008545 [48852] Win7Tools - Thumbnail - add rating stars 00001110 370.94885254 [48852] Win7Tools - Thumbnail - add rating stars 00001111 374.00991821 [48852] Win7Tools - Thumbnail - add rating stars 00001112 377.10089111 [48852] Win7Tools - Thumbnail - add rating stars 00001113 380.15957642 [48852] Win7Tools - Thumbnail - add rating stars 00001114 383.17990112 [48852] Win7Tools - Thumbnail - add rating stars 00001115 385.94409180 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 38 00001116 385.95010376 [48852] PostponeComputerSleep: Enabled = 0 00001117 385.95300293 [48852] Thread 'UpdateDriveLetters_Var' has started 48392 00001118 385.95306396 [48852] >UpdateDriveLetters - start< 00001119 385.96884155 [48852] >UpdateDriveLetters - end< 00001120 385.96890259 [48852] Going 'UpdateDriveLetters_Var'to make final callback 48392 00001121 385.96899414 [48852] Thread 'UpdateDriveLetters_Var'has finished 48392 00001122 386.24029541 [48852] Win7Tools - Thumbnail - add rating stars 00001123 389.36013794 [48852] Win7Tools - Thumbnail - add rating stars 00001124 392.37994385 [48852] Win7Tools - Thumbnail - add rating stars 00001125 395.48956299 [48852] Win7Tools - Thumbnail - add rating stars 00001126 398.54953003 [48852] Win7Tools - Thumbnail - add rating stars 00001127 401.60479736 [48852] Win7Tools - Thumbnail - add rating stars 00001128 404.65954590 [48852] Win7Tools - Thumbnail - add rating stars 00001129 407.76025391 [48852] Win7Tools - Thumbnail - add rating stars 00001130 410.80908203 [48852] Win7Tools - Thumbnail - add rating stars 00001131 413.89968872 [48852] Win7Tools - Thumbnail - add rating stars 00001132 415.94934082 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 37 00001133 415.95556641 [48852] PostponeComputerSleep: Enabled = 0 00001134 415.95819092 [48852] Thread 'UpdateDriveLetters_Var' has started 51252 00001135 415.95828247 [48852] >UpdateDriveLetters - start< 00001136 415.97372437 [48852] >UpdateDriveLetters - end< 00001137 415.97381592 [48852] Going 'UpdateDriveLetters_Var'to make final callback 51252 00001138 415.97390747 [48852] Thread 'UpdateDriveLetters_Var'has finished 51252 00001139 416.97003174 [48852] Win7Tools - Thumbnail - add rating stars 00001140 420.02609253 [48852] Win7Tools - Thumbnail - add rating stars 00001141 423.07086182 [48852] Win7Tools - Thumbnail - add rating stars 00001142 426.11071777 [48852] Win7Tools - Thumbnail - add rating stars 00001143 429.18988037 [48852] Win7Tools - Thumbnail - add rating stars 00001144 432.22482300 [48852] Win7Tools - Thumbnail - add rating stars 00001145 435.25979614 [48852] Win7Tools - Thumbnail - add rating stars 00001146 438.36993408 [48852] Win7Tools - Thumbnail - add rating stars 00001147 441.42996216 [48852] Win7Tools - Thumbnail - add rating stars 00001148 444.47488403 [48852] Win7Tools - Thumbnail - add rating stars 00001149 445.94622803 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 37 00001150 445.95236206 [48852] PostponeComputerSleep: Enabled = 0 00001151 445.95434570 [48852] Thread 'UpdateDriveLetters_Var' has started 49848 00001152 445.95446777 [48852] >UpdateDriveLetters - start< 00001153 445.96862793 [48852] >UpdateDriveLetters - end< 00001154 445.96868896 [48852] Going 'UpdateDriveLetters_Var'to make final callback 49848 00001155 445.96878052 [48852] Thread 'UpdateDriveLetters_Var'has finished 49848 00001156 447.57028198 [48852] Win7Tools - Thumbnail - add rating stars 00001157 450.59738159 [48852] Win7Tools - Thumbnail - add rating stars 00001158 453.68521118 [48852] Win7Tools - Thumbnail - add rating stars 00001159 456.70010376 [48852] Win7Tools - Thumbnail - add rating stars 00001160 459.76004028 [48852] Win7Tools - Thumbnail - add rating stars 00001161 462.80007935 [48852] Win7Tools - Thumbnail - add rating stars 00001162 465.87985229 [48852] Win7Tools - Thumbnail - add rating stars 00001163 468.97030640 [48852] Win7Tools - Thumbnail - add rating stars 00001164 472.09109497 [48852] Win7Tools - Thumbnail - add rating stars 00001165 475.16088867 [48852] Win7Tools - Thumbnail - add rating stars 00001166 475.95602417 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 39 00001167 475.97152710 [48852] PostponeComputerSleep: Enabled = 0 00001168 475.97399902 [48852] Thread 'UpdateDriveLetters_Var' has started 32580 00001169 475.97402954 [48852] >UpdateDriveLetters - start< 00001170 475.98925781 [48852] >UpdateDriveLetters - end< 00001171 475.98928833 [48852] Going 'UpdateDriveLetters_Var'to make final callback 32580 00001172 475.98941040 [48852] Thread 'UpdateDriveLetters_Var'has finished 32580 00001173 478.18020630 [48852] Win7Tools - Thumbnail - add rating stars 00001174 481.21533203 [48852] Win7Tools - Thumbnail - add rating stars 00001175 484.22979736 [48852] Win7Tools - Thumbnail - add rating stars 00001176 487.26010132 [48852] Win7Tools - Thumbnail - add rating stars 00001177 490.38012695 [48852] Win7Tools - Thumbnail - add rating stars 00001178 493.43002319 [48852] Win7Tools - Thumbnail - add rating stars 00001179 496.49002075 [48852] Win7Tools - Thumbnail - add rating stars 00001180 499.60028076 [48852] Win7Tools - Thumbnail - add rating stars 00001181 502.72030640 [48852] Win7Tools - Thumbnail - add rating stars 00001182 505.74008179 [48852] Win7Tools - Thumbnail - add rating stars 00001183 505.94390869 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 36 00001184 505.95001221 [48852] PostponeComputerSleep: Enabled = 0 00001185 505.95303345 [48852] Thread 'UpdateDriveLetters_Var' has started 19876 00001186 505.95312500 [48852] >UpdateDriveLetters - start< 00001187 505.96929932 [48852] >UpdateDriveLetters - end< 00001188 505.96936035 [48852] Going 'UpdateDriveLetters_Var'to make final callback 19876 00001189 505.96945190 [48852] Thread 'UpdateDriveLetters_Var'has finished 19876 00001190 508.83987427 [48852] Win7Tools - Thumbnail - add rating stars 00001191 511.86499023 [48852] Win7Tools - Thumbnail - add rating stars 00001192 514.91998291 [48852] Win7Tools - Thumbnail - add rating stars 00001193 518.00994873 [48852] Win7Tools - Thumbnail - add rating stars 00001194 521.07061768 [48852] Win7Tools - Thumbnail - add rating stars 00001195 524.09063721 [48852] Win7Tools - Thumbnail - add rating stars 00001196 527.16003418 [48852] Win7Tools - Thumbnail - add rating stars 00001197 530.21002197 [48852] Win7Tools - Thumbnail - add rating stars 00001198 533.30987549 [48852] Win7Tools - Thumbnail - add rating stars 00001199 535.94842529 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 1, All: 35 00001200 535.95446777 [48852] PostponeComputerSleep: Enabled = 0 00001201 535.95758057 [48852] Thread 'UpdateDriveLetters_Var' has started 42924 00001202 535.95770264 [48852] >UpdateDriveLetters - start< 00001203 535.97241211 [48852] >UpdateDriveLetters - end< 00001204 535.97253418 [48852] Going 'UpdateDriveLetters_Var'to make final callback 42924 00001205 535.97259521 [48852] Thread 'UpdateDriveLetters_Var'has finished 42924 00001206 536.41003418 [48852] Win7Tools - Thumbnail - add rating stars 00001207 539.48016357 [48852] Win7Tools - Thumbnail - add rating stars 00001208 542.54052734 [48852] Win7Tools - Thumbnail - add rating stars 00001209 545.34991455 [48852] Forms: Received WM_ACTIVATEAPP 00001210 545.34997559 [48852] Forms: Accepted WM_ACTIVATEAPP + 00001211 545.35003662 [48852] Forms: RestoreTopMost: Level: 1 00001212 545.35009766 [48852] Forms: RestoreTopMost: Starting 00001213 545.35052490 [48852] Winamp simulation window received messsage 28 00001214 545.35150146 [48852] MainForm: NC Activate + 00001215 545.36645508 [48852] MM4 [49844] TImagePlus.Paint: start 00001216 545.36688232 [48852] MM4 [49844] TImagePlus.Paint: finished 00001217 545.53027344 [48852] MM4 [49844] TImagePlus.Paint: start 00001218 545.53045654 [48852] MM4 [49844] TImagePlus.Paint: finished 00001219 545.56469727 [48852] Events: Invoking event: SetMnuVisibility 00001220 545.56494141 [48852] TEventedAutoObject Created, Class: TSDBTreeNode 00001221 545.56500244 [48852] TEventedAutoObject Created, Class: TSDBTreeNode 00001222 545.56683350 [48852] TEventedAutoObject Destroying, Class: TSDBTreeNode 00001223 545.56689453 [48852] TEventedAutoObject Destroying, Class: TSDBTreeNode 00001224 545.56689453 [48852] Events: Successfully finished event: SetMnuVisibility 00001225 545.56799316 [48852] Win7Tools - Thumbnail - add rating stars 00001226 546.92279053 [48852] DB: BEGIN EXCLUSIVE transaction 00001227 546.92321777 [48852] 49844 DB open SQL: SELECT ID,Album FROM Albums WHERE Album=? AND Artist=? 00001228 546.92333984 [48852] 49844 DB lock finished, took 390. 00001229 546.92346191 [48852] 49844 DB exec SQL: UPDATE Songs SET SongPath=?,Artist=?,IdAlbum=?,Album=?,AlbumArtist=?,SongTitle=?,Genre=?,Year=?,IDMedia=?,SongLength=?,PlaybackPos=?,StartTime=?,StopTime=?,SkipCount=?,TrackType=?,VideoHeight=?,VideoWidth=?,FrameRate=?,TrackNumber=?, EpisodeNumber=?, SeasonNumber=?, Actors=?, Producer=?, BitRate=?,FileLength=?,Seekable=?,SamplingFrequency=?,Stereo=?,VBR=?,BPM=?,Author=?,Rating=?,AudioCDTrack=?,FileModified=?,MaxSample=?,NormalizeTrack=?,NormalizeAlbum=?,DateAdded=?,LastTimePlayed=?,PlayCounter=?,Custom1=?,Custom2=?,Custom3=?,Custom4=?,Custom5=?,SignType=?,SignPart1=?,SignPart2=?,SignPart3=?,SignPart4=?,Copyright=?,Publisher=?,Encoder=?,Lyricist=?,Conductor=?,InvolvedPeople=?,OrigTitle=?,OrigArtist=?,OrigLyricist=?, ParentalRating=?,GroupDesc=?,SubTitle=?,ISRC=?,InitialKey=?,Language=?,OrigYear=?,Tempo=?,Mood=?,Occasion=?,Quality=?,Lyrics=?,Comment=?,DiscNumber=?,PreGap=?,PostGap=?,TotalSamples=?,GaplessBytes=?,TrackModified=?,ContainerType=?,StreamCount=?,StreamInfo=? WHERE ID=? 00001230 546.92358398 [48852] 49844 DB lock successful. 00001231 546.92700195 [48852] 49844 DB lock finished, took 33437. 00001232 546.92712402 [48852] 49844 DB open SQL: SELECT ID,Artist FROM Artists WHERE Artist=? 00001233 546.92718506 [48852] 49844 DB lock finished, took 213. 00001234 546.92724609 [48852] 49844 DB open SQL: SELECT null FROM ArtistsSongs WHERE PersonType = ? AND IDArtist=? AND IDSong=? AND TrackType = ? 00001235 546.92773438 [48852] 49844 DB lock finished, took 3775. 00001236 546.92779541 [48852] 49844 DB open SQL: SELECT IDGenre FROM Genres WHERE GenreName='Folk' 00001237 546.92785645 [48852] OpenQuery - Preparing query SELECT IDGenre FROM Genres WHERE GenreName='Folk' 00001238 546.92797852 [48852] 49844 DB lock finished, took 1295. 00001239 546.92810059 [48852] 49844 DB open SQL: SELECT IDGenre FROM Genres WHERE GenreName='Live' 00001240 546.92810059 [48852] OpenQuery - Preparing query SELECT IDGenre FROM Genres WHERE GenreName='Live' 00001241 546.92822266 [48852] 49844 DB lock finished, took 1048. 00001242 546.92834473 [48852] 49844 DB prepare SQL: SELECT null FROM GenresSongs WHERE IDGenre = ? AND IDSong = ? AND TrackType=? 00001243 546.92840576 [48852] 49844 DB query prepare finished, took 522. 00001244 546.92846680 [48852] 49844 DB open SQL: SELECT null FROM GenresSongs WHERE IDGenre = ? AND IDSong = ? AND TrackType=? 00001245 546.93347168 [48852] 49844 DB lock finished, took 48792. 00001246 546.93353271 [48852] 49844 DB open SQL: SELECT null FROM GenresSongs WHERE IDGenre = ? AND IDSong = ? AND TrackType=? 00001247 546.94030762 [48852] 49844 DB lock finished, took 67109. 00001248 546.94036865 [48852] 49844 DB exec SQL: DELETE FROM ArtistsSongs WHERE IDSong=361311 AND IDArtist NOT IN (16820) 00001249 546.94049072 [48852] 49844 DB lock successful. 00001250 546.94079590 [48852] 49844 DB lock finished, took 3130. 00001251 546.94091797 [48852] 49844 DB exec SQL: DELETE FROM GenresSongs WHERE IDSong=361311 AND IDGenre NOT IN (80,100073) 00001252 546.94097900 [48852] 49844 DB lock successful. 00001253 546.94122314 [48852] 49844 DB lock finished, took 1659. 00001254 546.94128418 [48852] Auto-Organizer : Begin checking track D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001255 546.94140625 [48852] 49844 DB open SQL: SELECT ID, Name, View FROM Views ORDER BY ID 00001256 546.94165039 [48852] 49844 DB lock finished, took 1594. 00001257 546.96130371 [48852] 49844 DB open SQL: SELECT * FROM Filters ORDER BY Pos 00001258 546.96148682 [48852] 49844 DB lock finished, took 2125. 00001259 546.96197510 [48852] Auto-Organizer : Checking rule:Collections:Muziek; \\lowlander03\Multimedia\$if(<Type>=Audiobook,Audiobooks,Music)\<Album Artist:1>\$Left(<Album Artist>,50)\[<Year>] $Left(<Album>,50)\$If(<Disc#>,<Disc#:2>-,)<Track#:2>. $Left(<Artist>,50) - $Left(<Title>,50)$if(<Type><>Audiobook,$if(<Rating>=0, (bad copy$),)) for filter 00001260 546.96203613 [48852] 49844 DB open SQL: SELECT Songs.ID FROM Songs WHERE Songs.ID=? AND ( (Songs.SongPath like '%\\lowlander03\Multimedia\Music\%') ) 00001261 546.96209717 [48852] 49844 DB lock finished, took 223. 00001262 546.96209717 [48852] Auto-Organizer : Track doesn't satisfy rule:Collections:Muziek; \\lowlander03\Multimedia\$if(<Type>=Audiobook,Audiobooks,Music)\<Album Artist:1>\$Left(<Album Artist>,50)\[<Year>] $Left(<Album>,50)\$If(<Disc#>,<Disc#:2>-,)<Track#:2>. $Left(<Artist>,50) - $Left(<Title>,50)$if(<Type><>Audiobook,$if(<Rating>=0, (bad copy$),)) 00001263 546.96209717 [48852] 49844 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6218 00001264 546.96209717 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6218 00001265 546.96221924 [48852] 49844 DB lock finished, took 657. 00001266 546.96228027 [48852] Auto-Organizer : Checking rule:Playlists:Global National; \\lowlander04\Multimedia\Podcasts\Global National\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - $Replace(<Title>,:,) for playlist 00001267 546.96228027 [48852] 49844 DB open SQL: SELECT Songs.Id AS SongID 00001268 546.96228027 [48852] FROM Songs WHERE Songs.ID = ? AND (Songs.Album like '%Global National%') AND Songs.TrackType in (1,7) 00001269 546.96234131 [48852] 49844 DB lock finished, took 70. 00001270 546.96234131 [48852] 49844 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6218 00001271 546.96240234 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6218 00001272 546.96240234 [48852] 49844 DB lock finished, took 423. 00001273 546.96246338 [48852] Auto-Organizer : Track doesn't satisfy rule:Playlists:Global National; \\lowlander04\Multimedia\Podcasts\Global National\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - $Replace(<Title>,:,) 00001274 546.96246338 [48852] 49844 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6220 00001275 546.96252441 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6220 00001276 546.96258545 [48852] 49844 DB lock finished, took 474. 00001277 546.96258545 [48852] Auto-Organizer : Checking rule:Playlists:NOS Journaal; \\lowlander04\Multimedia\Podcasts\NOS Journaal\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - Journaal van $Mid(<Title>,21) for playlist 00001278 546.96264648 [48852] 49844 DB open SQL: SELECT Songs.Id AS SongID 00001279 546.96264648 [48852] FROM Songs WHERE Songs.ID = ? AND (Songs.Album like '%NOS Journaal%') AND Songs.TrackType in (1,7) 00001280 546.96270752 [48852] 49844 DB lock finished, took 72. 00001281 546.96270752 [48852] 49844 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6220 00001282 546.96276855 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6220 00001283 546.96276855 [48852] 49844 DB lock finished, took 423. 00001284 546.96276855 [48852] Auto-Organizer : Track doesn't satisfy rule:Playlists:NOS Journaal; \\lowlander04\Multimedia\Podcasts\NOS Journaal\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - Journaal van $Mid(<Title>,21) 00001285 546.96282959 [48852] 49844 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6221 00001286 546.96282959 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6221 00001287 546.96289063 [48852] 49844 DB lock finished, took 407. 00001288 546.96295166 [48852] Auto-Organizer : Checking rule:Playlists:NOS Juegdjournaal; \\lowlander04\Multimedia\Podcasts\NOS Jeugdjournaal\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - Jeugdjournaal van $Mid(<Title>,19,10) $Right(<Title>,5) for playlist 00001289 546.96295166 [48852] 49844 DB open SQL: SELECT Songs.Id AS SongID 00001290 546.96295166 [48852] FROM Songs WHERE Songs.ID = ? AND (Songs.Album like '%NOS Jeugdjournaal%') AND Songs.TrackType in (1,7) 00001291 546.96301270 [48852] 49844 DB lock finished, took 66. 00001292 546.96307373 [48852] 49844 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6221 00001293 546.96307373 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6221 00001294 546.96307373 [48852] 49844 DB lock finished, took 405. 00001295 546.96313477 [48852] Auto-Organizer : Track doesn't satisfy rule:Playlists:NOS Juegdjournaal; \\lowlander04\Multimedia\Podcasts\NOS Jeugdjournaal\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - Jeugdjournaal van $Mid(<Title>,19,10) $Right(<Title>,5) 00001296 546.96313477 [48852] 49844 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6222 00001297 546.96319580 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6222 00001298 546.96325684 [48852] 49844 DB lock finished, took 400. 00001299 546.96325684 [48852] Auto-Organizer : Checking rule:Playlists:EenVandaag; \\lowlander04\Multimedia\Podcasts\EenVandaag\<Podcast> - s$Mid(<Title>,18)$Mid(<Title>,15,2)e$Right(<Date>,2) - <Title> for playlist 00001300 546.96331787 [48852] 49844 DB open SQL: SELECT Songs.Id AS SongID 00001301 546.96331787 [48852] FROM Songs WHERE Songs.ID = ? AND (Songs.Album like '%EénVandaag%') AND Songs.TrackType in (1,7) 00001302 546.96337891 [48852] 49844 DB lock finished, took 67. 00001303 546.96337891 [48852] 49844 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6222 00001304 546.96337891 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6222 00001305 546.96343994 [48852] 49844 DB lock finished, took 402. 00001306 546.96343994 [48852] Auto-Organizer : Track doesn't satisfy rule:Playlists:EenVandaag; \\lowlander04\Multimedia\Podcasts\EenVandaag\<Podcast> - s$Mid(<Title>,18)$Mid(<Title>,15,2)e$Right(<Date>,2) - <Title> 00001307 546.96350098 [48852] 49844 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6223 00001308 546.96350098 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6223 00001309 546.96356201 [48852] 49844 DB lock finished, took 394. 00001310 546.96362305 [48852] Auto-Organizer : Checking rule:Playlists:Nieuwsuur; \\lowlander04\Multimedia\Podcasts\Nieuwsuur\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - Nieuwsuur van $Mid(<Title>,11,10) for playlist 00001311 546.96362305 [48852] 49844 DB open SQL: SELECT Songs.Id AS SongID 00001312 546.96362305 [48852] FROM Songs WHERE Songs.ID = ? AND (Songs.Album like '%Nieuwsuur%') AND Songs.TrackType in (1,7) 00001313 546.96368408 [48852] 49844 DB lock finished, took 65. 00001314 546.96368408 [48852] 49844 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6223 00001315 546.96368408 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6223 00001316 546.96374512 [48852] 49844 DB lock finished, took 398. 00001317 546.96380615 [48852] Auto-Organizer : Track doesn't satisfy rule:Playlists:Nieuwsuur; \\lowlander04\Multimedia\Podcasts\Nieuwsuur\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - Nieuwsuur van $Mid(<Title>,11,10) 00001318 546.96380615 [48852] 49844 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6224 00001319 546.96386719 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6224 00001320 546.96392822 [48852] 49844 DB lock finished, took 399. 00001321 546.96392822 [48852] Auto-Organizer : Checking rule:Playlists:Tagesschau; \\lowlander04\Multimedia\Podcasts\Tagesschau\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - Tagesschau von $Left(<Title>,10) for playlist 00001322 546.96398926 [48852] 49844 DB open SQL: SELECT Songs.Id AS SongID 00001323 546.96398926 [48852] FROM Songs WHERE Songs.ID = ? AND (Songs.Album like '%Tagesschau%') AND Songs.TrackType in (1,7) 00001324 546.96398926 [48852] 49844 DB lock finished, took 68. 00001325 546.96405029 [48852] 49844 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6224 00001326 546.96405029 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6224 00001327 546.96411133 [48852] 49844 DB lock finished, took 610. 00001328 546.96417236 [48852] Auto-Organizer : Track doesn't satisfy rule:Playlists:Tagesschau; \\lowlander04\Multimedia\Podcasts\Tagesschau\<Podcast> - s$Replace(<Date:7>,-,)e$Right(<Date>,2) - Tagesschau von $Left(<Title>,10) 00001329 546.96423340 [48852] 49844 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6225 00001330 546.96423340 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6225 00001331 546.96429443 [48852] 49844 DB lock finished, took 407. 00001332 546.96435547 [48852] Auto-Organizer : Checking rule:Playlists:Talking Cars; \\lowlander04\Multimedia\Podcasts\Talking Cars\<Podcast> - s01e$Trim($Replace($Replace($Mid(<Title>,2,4),-),#)) - <Title> for playlist 00001333 546.96435547 [48852] 49844 DB open SQL: SELECT Songs.Id AS SongID 00001334 546.96435547 [48852] FROM Songs WHERE Songs.ID = ? AND (Songs.Album like '%Talking Cars%') AND Songs.TrackType in (1,7) 00001335 546.96435547 [48852] 49844 DB lock finished, took 68. 00001336 546.96441650 [48852] 49844 DB open SQL: SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6225 00001337 546.96441650 [48852] OpenQuery - Preparing query SELECT Playlists.PlaylistName FROM Playlists WHERE IDPlaylist=6225 00001338 546.96447754 [48852] 49844 DB lock finished, took 400. 00001339 546.96453857 [48852] Auto-Organizer : Track doesn't satisfy rule:Playlists:Talking Cars; \\lowlander04\Multimedia\Podcasts\Talking Cars\<Podcast> - s01e$Trim($Replace($Replace($Mid(<Title>,2,4),-),#)) - <Title> 00001340 546.96453857 [48852] 49844 DB open SQL: SELECT Count(*) FROM PathProcessing 00001341 546.96459961 [48852] 49844 DB lock finished, took 103. 00001342 546.96466064 [48852] 49844 DB open SQL: SELECT * FROM Artists WHERE Artist=? 00001343 546.96472168 [48852] 49844 DB lock finished, took 488. 00001344 546.96472168 [48852] TBackgroundTagger.UpdateTags, Count = 1 00001345 546.96478271 [48852] TBackgroundTagger.UpdateTags: Got BTLockCS 00001346 546.96478271 [48852] Tagging: New thread starting 00001347 546.96484375 [48852] Tagging: Queuing finished 00001348 546.98840332 [48852] TGenThread.Create: ThreadName: _DoTag , Running Threads: Internal: 1, All: 41 00001349 546.99688721 [48852] Win7Tools - Thumbnail - add rating stars 00001350 546.99749756 [48852] Thread '_DoTag' has started 47832 00001351 546.99768066 [48852] Tagging: Track will be tagged now: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001352 546.99768066 [48852] PrepareForTagging: called 00001353 546.99780273 [48852] PrepareForTagging: Our track is playing 00001354 547.00885010 [48852] IntPlay: Play thread Finishing Playback 00001355 547.00897217 [48852] Going to execute format plug-in destructor. 00001356 547.00909424 [48852] FLAC: FORMAT_DecodeClose(). 00001357 547.00988770 [48852] IntPlay: Play thread Exit 00001358 547.01000977 [48852] Going 'PlayThreadProc'to make final callback 10752 00001359 547.01007080 [48852] Thread 'PlayThreadProc'has finished 10752 00001360 547.02868652 [48852] PrepareForTagging: Track is stopped for tagging 00001361 547.02917480 [48852] FH.WriteFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001362 547.02923584 [48852] f_flac: FORMAT_OpenFile 00001363 547.03033447 [48852] FH.WriteFileInfo: openned 00001364 547.03039551 [48852] f_flac: FORMAT_SetInteger 00001365 547.03045654 [48852] f_flac: FORMAT_SetInteger 00001366 547.03051758 [48852] f_flac: FORMAT_SetInteger 00001367 547.03057861 [48852] f_flac: FORMAT_SetInteger 00001368 547.03063965 [48852] f_flac: FORMAT_SetDouble 00001369 547.03070068 [48852] f_flac: FORMAT_SetInteger 00001370 547.03076172 [48852] f_flac: FORMAT_SetInteger 00001371 547.03076172 [48852] f_flac: FORMAT_SetInteger 00001372 547.03082275 [48852] f_flac: FORMAT_SetInteger 00001373 547.03088379 [48852] f_flac: FORMAT_SetString 00001374 547.03094482 [48852] f_flac: FORMAT_SetString 00001375 547.03100586 [48852] f_flac: FORMAT_SetString 00001376 547.03106689 [48852] f_flac: FORMAT_SetString 00001377 547.03112793 [48852] f_flac: FORMAT_SetString 00001378 547.03118896 [48852] f_flac: FORMAT_SetString 00001379 547.03125000 [48852] f_flac: FORMAT_SetString 00001380 547.03131104 [48852] f_flac: FORMAT_SetString 00001381 547.03137207 [48852] f_flac: FORMAT_SetString 00001382 547.03137207 [48852] f_flac: FORMAT_SetString 00001383 547.03143311 [48852] f_flac: FORMAT_SetString 00001384 547.03149414 [48852] f_flac: FORMAT_SetString 00001385 547.03155518 [48852] f_flac: FORMAT_SetString 00001386 547.03161621 [48852] f_flac: FORMAT_SetString 00001387 547.03167725 [48852] f_flac: FORMAT_SetString 00001388 547.03167725 [48852] f_flac: FORMAT_SetString 00001389 547.03173828 [48852] f_flac: FORMAT_SetString 00001390 547.03179932 [48852] f_flac: FORMAT_SetString 00001391 547.03186035 [48852] f_flac: FORMAT_SetString 00001392 547.03192139 [48852] f_flac: FORMAT_SetString 00001393 547.03198242 [48852] f_flac: FORMAT_SetString 00001394 547.03198242 [48852] f_flac: FORMAT_SetString 00001395 547.03204346 [48852] f_flac: FORMAT_SetString 00001396 547.03210449 [48852] f_flac: FORMAT_SetString 00001397 547.03216553 [48852] f_flac: FORMAT_SetString 00001398 547.03222656 [48852] f_flac: FORMAT_SetString 00001399 547.03228760 [48852] f_flac: FORMAT_SetString 00001400 547.03234863 [48852] f_flac: FORMAT_SetString 00001401 547.03234863 [48852] f_flac: FORMAT_SetString 00001402 547.03240967 [48852] f_flac: FORMAT_SetString 00001403 547.03247070 [48852] f_flac: FORMAT_SetString 00001404 547.03253174 [48852] f_flac: FORMAT_SetString 00001405 547.03259277 [48852] f_flac: FORMAT_SetDouble 00001406 547.03265381 [48852] f_flac: FORMAT_SetDouble 00001407 547.03265381 [48852] f_flac: FORMAT_SetDouble 00001408 547.03271484 [48852] FH.WriteFileInfo: going to tag artworks 00001409 547.03326416 [48852] MM4 [47832] UpdateSongPictures: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001410 547.03332520 [48852] Added Cover Lists: 2 00001411 547.03344727 [48852] GetFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001412 547.03350830 [48852] GetFileInfo: readPictures=spAlways 00001413 547.03356934 [48852] GetFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001414 547.03393555 [48852] FH.ReadFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001415 547.03393555 [48852] f_flac: FORMAT_OpenFile 00001416 547.03503418 [48852] FH.ReadFileInfo openned 00001417 547.03521729 [48852] Added Covers: 2 00001418 547.03533936 [48852] f_flac: FORMAT_CloseFile 00001419 547.03582764 [48852] 47832 DB prepare SQL: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00001420 547.03625488 [48852] 47832 DB query prepare finished, took 3604. 00001421 547.03637695 [48852] 47832 DB open SQL: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00001422 547.03668213 [48852] 47832 DB lock finished, took 2199. 00001423 547.03698730 [48852] GetFileInfo: Found in DB 00001424 547.03704834 [48852] MM4 [47832] UpdateSongPictures: CoverList.LoadForSongId, D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001425 547.03710938 [48852] 47832 DB open SQL: SELECT * FROM Covers WHERE IDSong=361311 ORDER BY CoverOrder 00001426 547.03717041 [48852] OpenQuery - Preparing query SELECT * FROM Covers WHERE IDSong=361311 ORDER BY CoverOrder 00001427 547.03747559 [48852] 47832 DB lock finished, took 2655. 00001428 547.03753662 [48852] Added Covers: 3 00001429 547.03765869 [48852] Remaining Covers: 2 00001430 547.03771973 [48852] FH.WriteFileInfo: artwork count = 1 00001431 547.03778076 [48852] f_flac: FORMAT_SetInteger 00001432 547.03784180 [48852] f_flac: FORMAT_SetBinary 00001433 547.03796387 [48852] Remaining Cover Lists: 1 00001434 547.03802490 [48852] FH.WriteFileInfo: artwork tagging finished 00001435 547.03802490 [48852] f_flac: FORMAT_UpdateTag 00001436 547.03808594 [48852] flacParser: UpdateTag 00001437 547.03814697 [48852] flacParser: ConvertMetadataToBlock BEGIN 00001438 547.03912354 [48852] flacParser: ConvertMetadataToBlock END 00001439 547.03918457 [48852] flacParser: ConvertAAToBlocks BEGIN 00001440 547.03930664 [48852] flacParser: ConvertAAToBlocks END 00001441 547.03936768 [48852] flacParser: AddPaddingBlock 00001442 547.04833984 [48852] FH.WriteFileInfo: updated 00001443 547.04840088 [48852] f_flac: FORMAT_CloseFile 00001444 547.04864502 [48852] Remaining Covers: 1 00001445 547.04913330 [48852] 47832 DB exec SQL: UPDATE Songs SET FileLength=27360830, TrackModified=43497.772855463,FileModified=43497.772855463 WHERE ID=361311 00001446 547.04919434 [48852] 47832 DB lock successful. 00001447 547.04968262 [48852] 47832 DB lock finished, took 4418. 00001448 547.05010986 [48852] RestoreFromTagging starting. 00001449 547.05120850 [48852] RestoreFromTagging starting. 00001450 547.05126953 [48852] RestoreFromTagging going to proceeed. 00001451 547.05133057 [48852] Player: Song is not cached, try to play the original file 00001452 547.05145264 [48852] Decoder: CreateDecoder() started 00001453 547.05151367 [48852] Going to execute format plug-in constructor. 00001454 547.05151367 [48852] FLAC: FORMAT_DecodeInit(). 00001455 547.05157471 [48852] FLAC: Going to create stream decoder. 00001456 547.05163574 [48852] FLAC: Stream decoder created. 00001457 547.05169678 [48852] FLAC: Calling FLAC__stream_decoder_init_stream(). 00001458 547.05175781 [48852] FLAC: Calling FLAC__stream_decoder_process_until_end_of_metadata(). 00001459 547.05181885 [48852] FLAC: StreamDecoderMetadataCallback. 00001460 547.05206299 [48852] FLAC: FORMAT_DecodeInit() finished. 00001461 547.05206299 [48852] Format plug-in constructor finished. 00001462 547.05212402 [48852] Decoder: CreateDecoder() finished successfuly 00001463 547.07806396 [48852] TGenThread.Create: ThreadName: PlayThreadProc , Running Threads: Internal: 1, All: 41 00001464 547.08679199 [48852] Thread 'PlayThreadProc' has started 49812 00001465 547.08685303 [48852] IntPlay: Play thread Enter 00001466 547.08691406 [48852] IntPlay: Play thread Open Output 00001467 547.08691406 [48852] IntPlay: Play thread Set Stream Info 00001468 547.10321045 [48852] IntPlay: Play thread SRate set 00001469 547.10327148 [48852] IntPlay: Play thread Set Volume 00001470 547.10333252 [48852] IntPlay: Play thread Main loop start 00001471 547.10333252 [48852] SynchronizingAfterTagging starting 00001472 547.10339355 [48852] Going to execute format plug-in seek method. 00001473 547.10339355 [48852] RestoreFromTagging finished. 00001474 547.10351563 [48852] Tagging: Track was tagged: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001475 547.10357666 [48852] Tagging: Thread finished 00001476 547.10363770 [48852] Going '_DoTag'to make final callback 47832 00001477 547.10375977 [48852] DB: Deleting prepared query: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00001478 547.10382080 [48852] Thread '_DoTag'has finished 47832 00001479 547.19818115 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001480 547.19976807 [48852] BQ: Starting a new task. 00001481 547.20031738 [48852] BQ: Currently running 0 threads of 1 00001482 547.20104980 [48852] BQ: Starting a new thread. 00001483 547.23266602 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 1, All: 41 00001484 547.23986816 [48852] Thread 'BackgroundQueue' has started 45236 00001485 547.23999023 [48852] 45236 DB exec SQL: UPDATE Songs SET LastTimePlayed=43497.772857662, TrackModified=43497.772857662 WHERE Id=361311 00001486 547.24011230 [48852] 45236 DB lock successful. 00001487 547.24078369 [48852] 45236 DB lock finished, took 5757. 00001488 547.26684570 [48852] Win7Tools - Thumbnail - add rating stars 00001489 547.28302002 [48852] Win7Tools - Thumbnail - new size set 00001490 547.30651855 [48852] TGenThread.Create: ThreadName: anonymous , Running Threads: Internal: 2, All: 42 00001491 547.31542969 [48852] Thread 'anonymous' has started 43984 00001492 547.31604004 [48852] MM4 [43984] UpdateSongPictures: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001493 547.31610107 [48852] Added Cover Lists: 2 00001494 547.31622314 [48852] GetFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001495 547.31628418 [48852] GetFileInfo: readPictures=spAlways 00001496 547.31634521 [48852] GetFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001497 547.31665039 [48852] FH.ReadFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001498 547.31671143 [48852] f_flac: FORMAT_OpenFile 00001499 547.31768799 [48852] FH.ReadFileInfo openned 00001500 547.31781006 [48852] Added Covers: 2 00001501 547.31793213 [48852] f_flac: FORMAT_CloseFile 00001502 547.31829834 [48852] 43984 DB prepare SQL: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00001503 547.31866455 [48852] 43984 DB query prepare finished, took 3081. 00001504 547.31878662 [48852] 43984 DB open SQL: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00001505 547.31890869 [48852] 43984 DB lock finished, took 810. 00001506 547.31921387 [48852] GetFileInfo: Found in DB 00001507 547.31927490 [48852] MM4 [43984] UpdateSongPictures: CoverList.LoadForSongId, D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001508 547.31933594 [48852] 43984 DB open SQL: SELECT * FROM Covers WHERE IDSong=361311 ORDER BY CoverOrder 00001509 547.31939697 [48852] OpenQuery - Preparing query SELECT * FROM Covers WHERE IDSong=361311 ORDER BY CoverOrder 00001510 547.31958008 [48852] 43984 DB lock finished, took 1572. 00001511 547.31958008 [48852] Added Covers: 3 00001512 547.31970215 [48852] Remaining Covers: 2 00001513 547.32751465 [48852] Win7Tools - Thumbnail - new size set 00001514 547.36297607 [48852] TGenThread.Create: ThreadName: anonymous , Running Threads: Internal: 3, All: 43 00001515 547.37426758 [48852] Thread 'anonymous' has started 49312 00001516 547.37506104 [48852] MM4 [49312] UpdateSongPictures: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001517 547.37518311 [48852] Added Cover Lists: 3 00001518 547.37524414 [48852] GetFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001519 547.37530518 [48852] GetFileInfo: readPictures=spAlways 00001520 547.37542725 [48852] GetFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001521 547.37579346 [48852] FH.ReadFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001522 547.37579346 [48852] f_flac: FORMAT_OpenFile 00001523 547.37695313 [48852] MM4 [49844] TImagePlus.Paint: start 00001524 547.37707520 [48852] FH.ReadFileInfo openned 00001525 547.37719727 [48852] Added Covers: 3 00001526 547.37731934 [48852] f_flac: FORMAT_CloseFile 00001527 547.37750244 [48852] MM4 [49844] TImagePlus.Paint: finished 00001528 547.37792969 [48852] 49312 DB prepare SQL: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00001529 547.37835693 [48852] 49312 DB query prepare finished, took 3819. 00001530 547.37841797 [48852] 49312 DB open SQL: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00001531 547.37860107 [48852] 49312 DB lock finished, took 991. 00001532 547.37890625 [48852] GetFileInfo: Found in DB 00001533 547.37896729 [48852] MM4 [49312] UpdateSongPictures: CoverList.LoadForSongId, D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\09. Bruce Cockburn - Pacing the Cage.flac 00001534 547.37908936 [48852] 49312 DB open SQL: SELECT * FROM Covers WHERE IDSong=361311 ORDER BY CoverOrder 00001535 547.37915039 [48852] OpenQuery - Preparing query SELECT * FROM Covers WHERE IDSong=361311 ORDER BY CoverOrder 00001536 547.37933350 [48852] 49312 DB lock finished, took 1918. 00001537 547.37945557 [48852] Added Covers: 4 00001538 547.37951660 [48852] Remaining Covers: 3 00001539 547.42932129 [48852] Win7Tools - Thumbnail - Cover should be loaded 00001540 547.42938232 [48852] Win7Tools - Thumbnail - Loading cover 00001541 547.43634033 [48852] MM4 [49844] TStretcher.PerformStretch: Threads[3], source[600, 545], target[106,96] 00001542 547.43640137 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001543 547.43640137 [48852] BQ: Starting a new task. 00001544 547.43646240 [48852] BQ: There are threads waiting, resume one. 00001545 547.43646240 [48852] BQ: Added new task. Currently 2 tasks in queue. 00001546 547.43646240 [48852] BQ: Starting a new task. 00001547 547.43646240 [48852] BQ: Currently running 1 threads of 8 00001548 547.43652344 [48852] BQ: Starting a new thread. 00001549 547.46636963 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 4, All: 44 00001550 547.47167969 [48852] MM4 [49844] TStretcher.PerformStretch: Finished 00001551 547.47222900 [48852] Win7Tools - Thumbnail - add rating stars 00001552 547.47326660 [48852] Remaining Cover Lists: 2 00001553 547.47357178 [48852] Remaining Covers: 2 00001554 547.47375488 [48852] Thread 'BackgroundQueue' has started 50520 00001555 547.47387695 [48852] Going 'anonymous'to make final callback 43984 00001556 547.47393799 [48852] DB: Deleting prepared query: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00001557 547.47399902 [48852] Win7Tools - Thumbnail - add rating stars 00001558 547.47406006 [48852] Thread 'anonymous'has finished 43984 00001559 547.47460938 [48852] Remaining Covers: 1 00001560 547.47460938 [48852] Remaining Cover Lists: 1 00001561 547.47479248 [48852] Going 'anonymous'to make final callback 49312 00001562 547.47485352 [48852] DB: Deleting prepared query: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00001563 547.47497559 [48852] Thread 'anonymous'has finished 49312 00001564 548.14947510 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001565 548.14953613 [48852] BQ: Starting a new task. 00001566 548.14965820 [48852] BQ: There are threads waiting, resume one. 00001567 548.14984131 [48852] 45236 DB open SQL: SELECT Songs.ID FROM Songs WHERE ( Songs.TrackType in (4) ) LIMIT 1 00001568 548.15008545 [48852] 45236 DB lock finished, took 1288. 00001569 549.20153809 [48852] TGenThread.Create: ThreadName: _ManageTransactions , Running Threads: Internal: 3, All: 40 00001570 549.20922852 [48852] Thread '_ManageTransactions' has started 49896 00001571 549.20928955 [48852] Going '_ManageTransactions'to make final callback 49896 00001572 549.20941162 [48852] Thread '_ManageTransactions'has finished 49896 00001573 549.97253418 [48852] MainForm: NC Activate - 00001574 549.97424316 [48852] Forms: Received WM_ACTIVATEAPP 00001575 549.97436523 [48852] Forms: Accepted WM_ACTIVATEAPP - 00001576 549.97448730 [48852] Forms: NormalizeTopMosts: Level: 0 00001577 549.97460938 [48852] Forms: NormalizeTopMost: Starting 00001578 549.97521973 [48852] Winamp simulation window received messsage 28 00001579 550.48901367 [48852] Going 'BackgroundQueue'to make final callback 50520 00001580 550.48907471 [48852] Thread 'BackgroundQueue'has finished 50520 00001581 550.49011230 [48852] Win7Tools - Thumbnail - add rating stars 00001582 551.16894531 [48852] Going 'BackgroundQueue'to make final callback 45236 00001583 551.16912842 [48852] Thread 'BackgroundQueue'has finished 45236 00001584 551.18865967 [48852] TGenThread.Create: ThreadName: _ManageTransactions , Running Threads: Internal: 2, All: 37 00001585 551.19702148 [48852] Thread '_ManageTransactions' has started 44160 00001586 551.19714355 [48852] Going '_ManageTransactions'to make final callback 44160 00001587 551.19726563 [48852] Thread '_ManageTransactions'has finished 44160 00001588 552.20910645 [48852] IntPlay: Play thread Finishing Playback 00001589 552.20922852 [48852] WASAPI: Close starts 00001590 552.20922852 [48852] WASAPI: Going to crossfade 00001591 552.20928955 [48852] WASAPI: Close ends 00001592 552.20941162 [48852] Going to execute format plug-in destructor. 00001593 552.20953369 [48852] FLAC: FORMAT_DecodeClose(). 00001594 552.21020508 [48852] IntPlay: Play thread Exit 00001595 552.21026611 [48852] Going 'PlayThreadProc'to make final callback 49812 00001596 552.21044922 [48852] Thread 'PlayThreadProc'has finished 49812 00001597 552.21051025 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001598 552.21051025 [48852] BQ: Starting a new task. 00001599 552.21063232 [48852] BQ: Currently running 0 threads of 1 00001600 552.21069336 [48852] BQ: Starting a new thread. 00001601 552.26000977 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 0, All: 39 00001602 552.26721191 [48852] 49844 DB open SQL: Select * FROM Filters Order BY ID 00001603 552.26727295 [48852] Thread 'BackgroundQueue' has started 50380 00001604 552.26739502 [48852] OpenQuery - Preparing query Select * FROM Filters Order BY ID 00001605 552.26757813 [48852] 50380 DB exec SQL: INSERT INTO Played (IdSong,PlayDate,UTCOffset) VALUES (361311,43497.772915822,-0.333333333) 00001606 552.26763916 [48852] 49844 DB lock finished, took 2951. 00001607 552.26763916 [48852] 50380 DB lock successful. 00001608 552.26788330 [48852] 50380 DB lock finished, took 1926. 00001609 552.26794434 [48852] 50380 DB exec SQL: UPDATE Songs SET PlayCounter=1,LastTimePlayed=43497.772915822, TrackModified=43497.772915822, PlaybackPos = 0 WHERE Id=361311 00001610 552.26800537 [48852] 50380 DB lock successful. 00001611 552.26824951 [48852] 50380 DB lock finished, took 2330. 00001612 552.26867676 [48852] Player: Next command started 00001613 552.26873779 [48852] _Stop: started 00001614 552.26904297 [48852] 50412 DB prepare SQL: SELECT * FROM Filters WHERE ID=? 00001615 552.26922607 [48852] 50412 DB query prepare finished, took 640. 00001616 552.26928711 [48852] 50412 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001617 552.26934814 [48852] 50412 DB lock finished, took 174. 00001618 552.26953125 [48852] 50412 DB prepare SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001619 552.26959229 [48852] 50412 DB query prepare finished, took 378. 00001620 552.26965332 [48852] 50412 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001621 552.26977539 [48852] 50412 DB lock finished, took 170. 00001622 552.27056885 [48852] 50412 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001623 552.27062988 [48852] 50412 DB lock finished, took 155. 00001624 552.27075195 [48852] 50412 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001625 552.27087402 [48852] 50412 DB lock finished, took 129. 00001626 552.27154541 [48852] 50412 DB open SQL: SELECT Songs.* 00001627 552.27154541 [48852] FROM Songs 00001628 552.27154541 [48852] WHERE Songs.id=361311 AND Songs.TrackType in (4) 00001629 552.27160645 [48852] OpenQuery - Preparing query SELECT Songs.* 00001630 552.27160645 [48852] FROM Songs 00001631 552.27160645 [48852] WHERE Songs.id=361311 AND Songs.TrackType in (4) 00001632 552.27203369 [48852] 50412 DB lock finished, took 3559. 00001633 552.27215576 [48852] 50412 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001634 552.27221680 [48852] 50412 DB lock finished, took 144. 00001635 552.27233887 [48852] 50412 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001636 552.27246094 [48852] 50412 DB lock finished, took 143. 00001637 552.27313232 [48852] 50412 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001638 552.27325439 [48852] 50412 DB lock finished, took 145. 00001639 552.27337646 [48852] 50412 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001640 552.27343750 [48852] 50412 DB lock finished, took 123. 00001641 552.27423096 [48852] 50412 DB open SQL: SELECT Songs.* 00001642 552.27423096 [48852] FROM Songs 00001643 552.27423096 [48852] WHERE Songs.id=361311 AND Songs.TrackType in (1,4,5,6,7) 00001644 552.27429199 [48852] OpenQuery - Preparing query SELECT Songs.* 00001645 552.27429199 [48852] FROM Songs 00001646 552.27429199 [48852] WHERE Songs.id=361311 AND Songs.TrackType in (1,4,5,6,7) 00001647 552.27465820 [48852] 50412 DB lock finished, took 3503. 00001648 552.27471924 [48852] 50412 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001649 552.27484131 [48852] 50412 DB lock finished, took 148. 00001650 552.27496338 [48852] 50412 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001651 552.27502441 [48852] 50412 DB lock finished, took 135. 00001652 552.27575684 [48852] 50412 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001653 552.27587891 [48852] 50412 DB lock finished, took 149. 00001654 552.27593994 [48852] 50412 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001655 552.27606201 [48852] 50412 DB lock finished, took 118. 00001656 552.27679443 [48852] 50412 DB open SQL: SELECT Songs.* 00001657 552.27679443 [48852] FROM Songs 00001658 552.27679443 [48852] WHERE Songs.id=361311 AND ((Songs.SongPath like '%\TV\%')) 00001659 552.27685547 [48852] OpenQuery - Preparing query SELECT Songs.* 00001660 552.27685547 [48852] FROM Songs 00001661 552.27685547 [48852] WHERE Songs.id=361311 AND ((Songs.SongPath like '%\TV\%')) 00001662 552.27722168 [48852] 50412 DB lock finished, took 3262. 00001663 552.27728271 [48852] 50412 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001664 552.27740479 [48852] 50412 DB lock finished, took 140. 00001665 552.27752686 [48852] 50412 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001666 552.27758789 [48852] 50412 DB lock finished, took 164. 00001667 552.27850342 [48852] 50412 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001668 552.27856445 [48852] 50412 DB lock finished, took 150. 00001669 552.27874756 [48852] 50412 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001670 552.27880859 [48852] 50412 DB lock finished, took 144. 00001671 552.27966309 [48852] 50412 DB open SQL: SELECT Songs.* 00001672 552.27966309 [48852] FROM Songs 00001673 552.27966309 [48852] WHERE Songs.id=361311 AND ((Songs.SongPath like '%\Movies\%')) 00001674 552.27978516 [48852] OpenQuery - Preparing query SELECT Songs.* 00001675 552.27978516 [48852] FROM Songs 00001676 552.27978516 [48852] WHERE Songs.id=361311 AND ((Songs.SongPath like '%\Movies\%')) 00001677 552.28009033 [48852] 50412 DB lock finished, took 3265. 00001678 552.28021240 [48852] 50412 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001679 552.28027344 [48852] 50412 DB lock finished, took 151. 00001680 552.28039551 [48852] 50412 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001681 552.28045654 [48852] 50412 DB lock finished, took 135. 00001682 552.28118896 [48852] 50412 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001683 552.28125000 [48852] 50412 DB lock finished, took 158. 00001684 552.28137207 [48852] 50412 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001685 552.28143311 [48852] 50412 DB lock finished, took 116. 00001686 552.28210449 [48852] 50412 DB open SQL: SELECT Songs.* 00001687 552.28210449 [48852] FROM Songs 00001688 552.28210449 [48852] WHERE Songs.id=361311 AND (Songs.SongPath like '%\\lowlander04\Multimedia\Family Videos\%') AND NOT (Songs.SongPath like '%Plex%') 00001689 552.28222656 [48852] OpenQuery - Preparing query SELECT Songs.* 00001690 552.28222656 [48852] FROM Songs 00001691 552.28222656 [48852] WHERE Songs.id=361311 AND (Songs.SongPath like '%\\lowlander04\Multimedia\Family Videos\%') AND NOT (Songs.SongPath like '%Plex%') 00001692 552.28253174 [48852] 50412 DB lock finished, took 3397. 00001693 552.30364990 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001694 552.30364990 [48852] BQ: Starting a new task. 00001695 552.30371094 [48852] BQ: Currently running 1 threads of 1 00001696 552.30371094 [48852] BQ: A new thread isn't needed. 00001697 552.30383301 [48852] PrepareDockedVideo: Begin 00001698 552.30383301 [48852] PrepareDockedVideo: Switching=true IsStartingPlayback=false WasManuallyChanged=false 00001699 552.30389404 [48852] _Stop: finished 00001700 552.30389404 [48852] Player: Setting current track: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\10. Bruce Cockburn - Bearded Folksinger.flac 00001701 552.30389404 [48852] Player: Next track prepared, going to start playback 00001702 552.32788086 [48852] TGenThread.Create: ThreadName: PlaybackStarter_Var , Running Threads: Internal: 1, All: 41 00001703 552.33435059 [48852] PrepareDockedVideo: Begin 00001704 552.33441162 [48852] PrepareDockedVideo: Switching=true IsStartingPlayback=true WasManuallyChanged=true 00001705 552.33441162 [48852] Remaining Cover Lists: 0 00001706 552.33441162 [48852] BQ: Added new task. Currently 2 tasks in queue. 00001707 552.33447266 [48852] BQ: Starting a new task. 00001708 552.33447266 [48852] BQ: Currently running 1 threads of 8 00001709 552.33453369 [48852] BQ: Starting a new thread. 00001710 552.33679199 [48852] Thread 'PlaybackStarter_Var' has started 50988 00001711 552.33691406 [48852] Player: _Play() procedure entering. 00001712 552.34332275 [48852] Player: W7 icon updated. 00001713 552.34338379 [48852] Player: Going to handle the current track. 00001714 552.34350586 [48852] Player: Updating playlist entry. 00001715 552.34362793 [48852] Player: Setting current track: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\10. Bruce Cockburn - Bearded Folksinger.flac 00001716 552.34362793 [48852] Player: Track entry prepared, going to start playback. 00001717 552.34375000 [48852] Player: Song is not cached, try to play the original file 00001718 552.34423828 [48852] Going to play file: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\10. Bruce Cockburn - Bearded Folksinger.flac 00001719 552.34436035 [48852] Player: Playback started 00001720 552.35943604 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 1, All: 41 00001721 552.36505127 [48852] 49844 DB open SQL: SELECT Lyrics, Comment FROM Songs WHERE Songs.ID=? 00001722 552.36511230 [48852] 49844 DB lock finished, took 352. 00001723 552.36712646 [48852] Thread 'BackgroundQueue' has started 52248 00001724 552.38964844 [48852] TGenThread.Create: ThreadName: SearchLyricsOnBackgroud_Var , Running Threads: Internal: 2, All: 42 00001725 552.39270020 [48852] MM4 [52248] UpdateSongPictures: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\10. Bruce Cockburn - Bearded Folksinger.flac 00001726 552.39288330 [48852] Added Cover Lists: 1 00001727 552.39294434 [48852] GetFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\10. Bruce Cockburn - Bearded Folksinger.flac 00001728 552.39300537 [48852] GetFileInfo: readPictures=spAlways 00001729 552.39312744 [48852] GetFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\10. Bruce Cockburn - Bearded Folksinger.flac 00001730 552.39349365 [48852] FH.ReadFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\10. Bruce Cockburn - Bearded Folksinger.flac 00001731 552.39355469 [48852] f_flac: FORMAT_OpenFile 00001732 552.39654541 [48852] MM4 [49844] TLyricsScroller.createOverlay: rows: 2 00001733 552.39703369 [48852] MM4 [49844] TLyricsScroller.createOverlay: finished 00001734 552.39727783 [48852] MM4 [49844] TLyricsScroller.createOverlay: rows: 2 00001735 552.39837646 [48852] MM4 [49844] TLyricsScroller.createOverlay: finished 00001736 552.39862061 [48852] Thread 'SearchLyricsOnBackgroud_Var' has started 52324 00001737 552.39874268 [48852] MM4 [49844] TImagePlus.Paint: start 00001738 552.39892578 [48852] Current User Scripts Folder: C:\Users\mwarn\AppData\Roaming\MediaMonkey\Scripts\ 00001739 552.39923096 [48852] MM4 [49844] TImagePlus.Paint: finished 00001740 552.40161133 [48852] FH.ReadFileInfo openned 00001741 552.40179443 [48852] Added Covers: 2 00001742 552.40185547 [48852] f_flac: FORMAT_CloseFile 00001743 552.40228271 [48852] 52248 DB prepare SQL: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00001744 552.40270996 [48852] 52248 DB query prepare finished, took 3184. 00001745 552.40277100 [48852] 52248 DB open SQL: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00001746 552.40295410 [48852] 52248 DB lock finished, took 690. 00001747 552.40325928 [48852] GetFileInfo: Found in DB 00001748 552.40338135 [48852] MM4 [52248] UpdateSongPictures: CoverList.LoadForSongId, D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\10. Bruce Cockburn - Bearded Folksinger.flac 00001749 552.40338135 [48852] 52248 DB open SQL: SELECT * FROM Covers WHERE IDSong=361312 ORDER BY CoverOrder 00001750 552.40344238 [48852] OpenQuery - Preparing query SELECT * FROM Covers WHERE IDSong=361312 ORDER BY CoverOrder 00001751 552.40368652 [48852] 52248 DB lock finished, took 2024. 00001752 552.40368652 [48852] Added Covers: 3 00001753 552.40380859 [48852] Remaining Covers: 2 00001754 552.40594482 [48852] TScriptExec.RunProcedure: SearchLyrics 00001755 552.40612793 [48852] lyricsSearch.js: SearchLyrics: Artist: Bruce Cockburn ,Title: Bearded Folksinger ,currentRequest = 0 00001756 552.40625000 [48852] lyricsSearch.js: init 00001757 552.40637207 [48852] lyricsSearch.js: whatNext init 00001758 552.40643311 [48852] lyricsSearch.js: Calling search send 00001759 552.40655518 [48852] lyricsSearch.js: SearchSend 00001760 552.40814209 [48852] TIndyHTTP.GetResponseContent started: URL: http://lyrics.wikia.com/wiki/Bruce_Cockburn:Bearded_Folksinger, RequestBody: 00001761 552.42181396 [48852] Win7Tools - Thumbnail - new size set 00001762 552.44628906 [48852] TGenThread.Create: ThreadName: anonymous , Running Threads: Internal: 3, All: 45 00001763 552.45324707 [48852] Winamp simulation window received messsage 12 00001764 552.45343018 [48852] BQ: Added new task. Currently 2 tasks in queue. 00001765 552.45355225 [48852] BQ: Starting a new task. 00001766 552.45379639 [48852] BQ: Currently running 2 threads of 8 00001767 552.45397949 [48852] BQ: Starting a new thread. 00001768 552.45501709 [48852] Thread 'anonymous' has started 49116 00001769 552.45556641 [48852] MM4 [49116] UpdateSongPictures: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\10. Bruce Cockburn - Bearded Folksinger.flac 00001770 552.45568848 [48852] Added Cover Lists: 2 00001771 552.45574951 [48852] GetFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\10. Bruce Cockburn - Bearded Folksinger.flac 00001772 552.45581055 [48852] GetFileInfo: readPictures=spAlways 00001773 552.45581055 [48852] GetFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\10. Bruce Cockburn - Bearded Folksinger.flac 00001774 552.45611572 [48852] FH.ReadFileInfo: D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\10. Bruce Cockburn - Bearded Folksinger.flac 00001775 552.45617676 [48852] f_flac: FORMAT_OpenFile 00001776 552.45709229 [48852] FH.ReadFileInfo openned 00001777 552.45721436 [48852] Added Covers: 3 00001778 552.45733643 [48852] f_flac: FORMAT_CloseFile 00001779 552.45770264 [48852] 49116 DB prepare SQL: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00001780 552.45806885 [48852] 49116 DB query prepare finished, took 3057. 00001781 552.45812988 [48852] 49116 DB open SQL: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00001782 552.45831299 [48852] 49116 DB lock finished, took 637. 00001783 552.45855713 [48852] GetFileInfo: Found in DB 00001784 552.45867920 [48852] MM4 [49116] UpdateSongPictures: CoverList.LoadForSongId, D:\Media\TempMusic\Bruce Cockburn\Slice O Life- Live Solo (Disc 1 of 2)\10. Bruce Cockburn - Bearded Folksinger.flac 00001785 552.45867920 [48852] 49116 DB open SQL: SELECT * FROM Covers WHERE IDSong=361312 ORDER BY CoverOrder 00001786 552.45874023 [48852] OpenQuery - Preparing query SELECT * FROM Covers WHERE IDSong=361312 ORDER BY CoverOrder 00001787 552.45892334 [48852] 49116 DB lock finished, took 1593. 00001788 552.45898438 [48852] Added Covers: 4 00001789 552.45910645 [48852] Remaining Covers: 3 00001790 552.47814941 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 3, All: 45 00001791 552.48583984 [48852] Thread 'BackgroundQueue' has started 30196 00001792 552.48596191 [48852] 30196 DB open SQL: SELECT Playlists.IDPlaylist, Playlists.PlaylistName FROM Playlists WHERE Playlists.IDPlaylist IN (SELECT PlaylistSongs.IDPlaylist FROM PlaylistSongs WHERE PlaylistSongs.IDSong IN (SELECT ID FROM Songs ORDER BY LastTimePlayed DESC LIMIT 200) GROUP BY PlaylistSongs.IDPlaylist) LIMIT 10 00001793 552.48602295 [48852] OpenQuery - Preparing query SELECT Playlists.IDPlaylist, Playlists.PlaylistName FROM Playlists WHERE Playlists.IDPlaylist IN (SELECT PlaylistSongs.IDPlaylist FROM PlaylistSongs WHERE PlaylistSongs.IDSong IN (SELECT ID FROM Songs ORDER BY LastTimePlayed DESC LIMIT 200) GROUP BY PlaylistSongs.IDPlaylist) LIMIT 10 00001794 552.48767090 [48852] 30196 DB lock finished, took 16406. 00001795 552.49523926 [48852] PrepareDockedVideo: Begin 00001796 552.49530029 [48852] PrepareDockedVideo: Switching=true IsStartingPlayback=true WasManuallyChanged=true 00001797 552.49536133 [48852] PrepareDockedVideo: Begin 00001798 552.49542236 [48852] PrepareDockedVideo: Switching=true IsStartingPlayback=true WasManuallyChanged=false 00001799 552.50415039 [48852] MM4 [49844] TStretcher.PerformStretch: Threads[5], source[600, 545], target[160,145] 00001800 552.50415039 [48852] BQ: Added new task. Currently 2 tasks in queue. 00001801 552.50421143 [48852] BQ: Starting a new task. 00001802 552.50421143 [48852] BQ: Currently running 3 threads of 8 00001803 552.50427246 [48852] BQ: Starting a new thread. 00001804 552.53173828 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 5, All: 44 00001805 552.53741455 [48852] BQ: Added new task. Currently 3 tasks in queue. 00001806 552.53741455 [48852] BQ: Starting a new task. 00001807 552.53747559 [48852] BQ: Currently running 4 threads of 8 00001808 552.53747559 [48852] BQ: Starting a new thread. 00001809 552.53857422 [48852] Thread 'BackgroundQueue' has started 51052 00001810 552.56628418 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 5, All: 45 00001811 552.57183838 [48852] BQ: Added new task. Currently 4 tasks in queue. 00001812 552.57183838 [48852] BQ: Starting a new task. 00001813 552.57189941 [48852] BQ: Currently running 5 threads of 8 00001814 552.57196045 [48852] BQ: Starting a new thread. 00001815 552.57409668 [48852] Thread 'BackgroundQueue' has started 44212 00001816 552.60028076 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 6, All: 46 00001817 552.60577393 [48852] BQ: Added new task. Currently 4 tasks in queue. 00001818 552.60577393 [48852] BQ: Starting a new task. 00001819 552.60577393 [48852] BQ: There are threads waiting, resume one. 00001820 552.60589600 [48852] MM4 [49844] TStretcher.PerformStretch: Finished 00001821 552.60675049 [48852] Thread 'BackgroundQueue' has started 12412 00001822 552.61053467 [48852] Win7Tools - Thumbnail - Cover should be loaded 00001823 552.61053467 [48852] Win7Tools - Thumbnail - Loading cover 00001824 552.61785889 [48852] MM4 [49844] TStretcher.PerformStretch: Threads[3], source[600, 545], target[106,96] 00001825 552.61785889 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001826 552.61791992 [48852] BQ: Starting a new task. 00001827 552.61791992 [48852] BQ: There are threads waiting, resume one. 00001828 552.61798096 [48852] BQ: Added new task. Currently 2 tasks in queue. 00001829 552.61798096 [48852] BQ: Starting a new task. 00001830 552.61804199 [48852] BQ: There are threads waiting, resume one. 00001831 552.62304688 [48852] MM4 [49844] TStretcher.PerformStretch: Finished 00001832 552.62371826 [48852] Win7Tools - Thumbnail - add rating stars 00001833 552.62408447 [48852] Remaining Cover Lists: 1 00001834 552.62420654 [48852] Remaining Covers: 2 00001835 552.62426758 [48852] Going 'anonymous'to make final callback 49116 00001836 552.62432861 [48852] DB: Deleting prepared query: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00001837 552.62451172 [48852] Thread 'anonymous'has finished 49116 00001838 552.62609863 [48852] Winamp Playlist sim - WM_USER message 27 00001839 552.62615967 [48852] Winamp Playlist sim - message left to the default processing 00001840 552.62640381 [48852] Winamp Playlist sim - WM_USER message 1073741851 00001841 552.62646484 [48852] Winamp Playlist sim - message left to the default processing 00001842 552.62927246 [48852] 49844 DB open SQL: Select * FROM Filters Order BY ID 00001843 552.62927246 [48852] OpenQuery - Preparing query Select * FROM Filters Order BY ID 00001844 552.62939453 [48852] 49844 DB lock finished, took 1003. 00001845 552.62976074 [48852] Going 'PlaybackStarter_Var'to make final callback 50988 00001846 552.62982178 [48852] Thread 'PlaybackStarter_Var'has finished 50988 00001847 552.63012695 [48852] Remaining Covers: 1 00001848 552.63018799 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001849 552.63024902 [48852] BQ: Starting a new task. 00001850 552.63031006 [48852] BQ: There are threads waiting, resume one. 00001851 552.63037109 [48852] 41140 DB prepare SQL: SELECT * FROM Filters WHERE ID=? 00001852 552.63079834 [48852] 41140 DB query prepare finished, took 449. 00001853 552.63085938 [48852] 41140 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001854 552.63092041 [48852] 41140 DB lock finished, took 290. 00001855 552.63110352 [48852] MM4 [49844] TImagePlus.Paint: start 00001856 552.63110352 [48852] 41140 DB prepare SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001857 552.63122559 [48852] 41140 DB query prepare finished, took 513. 00001858 552.63128662 [48852] 41140 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001859 552.63140869 [48852] 41140 DB lock finished, took 191. 00001860 552.63146973 [48852] MM4 [49844] TImagePlus.Paint: finished 00001861 552.63226318 [48852] 41140 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001862 552.63238525 [48852] 41140 DB lock finished, took 184. 00001863 552.63250732 [48852] 41140 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001864 552.63256836 [48852] 41140 DB lock finished, took 141. 00001865 552.63342285 [48852] 41140 DB open SQL: SELECT Songs.* 00001866 552.63342285 [48852] FROM Songs 00001867 552.63342285 [48852] WHERE Songs.id=361312 AND Songs.TrackType in (4) 00001868 552.63342285 [48852] OpenQuery - Preparing query SELECT Songs.* 00001869 552.63342285 [48852] FROM Songs 00001870 552.63342285 [48852] WHERE Songs.id=361312 AND Songs.TrackType in (4) 00001871 552.63385010 [48852] 41140 DB lock finished, took 3923. 00001872 552.63403320 [48852] 41140 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001873 552.63409424 [48852] 41140 DB lock finished, took 170. 00001874 552.63421631 [48852] 41140 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001875 552.63433838 [48852] 41140 DB lock finished, took 158. 00001876 552.63513184 [48852] 41140 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001877 552.63525391 [48852] 41140 DB lock finished, took 168. 00001878 552.63531494 [48852] 41140 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001879 552.63543701 [48852] 41140 DB lock finished, took 136. 00001880 552.63629150 [48852] 41140 DB open SQL: SELECT Songs.* 00001881 552.63629150 [48852] FROM Songs 00001882 552.63629150 [48852] WHERE Songs.id=361312 AND Songs.TrackType in (1,4,5,6,7) 00001883 552.63629150 [48852] OpenQuery - Preparing query SELECT Songs.* 00001884 552.63629150 [48852] FROM Songs 00001885 552.63629150 [48852] WHERE Songs.id=361312 AND Songs.TrackType in (1,4,5,6,7) 00001886 552.63677979 [48852] 41140 DB lock finished, took 4142. 00001887 552.63690186 [48852] 41140 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001888 552.63702393 [48852] 41140 DB lock finished, took 172. 00001889 552.63714600 [48852] 41140 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001890 552.63720703 [48852] 41140 DB lock finished, took 150. 00001891 552.63806152 [48852] 41140 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001892 552.63812256 [48852] 41140 DB lock finished, took 165. 00001893 552.63824463 [48852] 41140 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001894 552.63830566 [48852] 41140 DB lock finished, took 132. 00001895 552.63909912 [48852] 41140 DB open SQL: SELECT Songs.* 00001896 552.63909912 [48852] FROM Songs 00001897 552.63909912 [48852] WHERE Songs.id=361312 AND ((Songs.SongPath like '%\TV\%')) 00001898 552.63922119 [48852] OpenQuery - Preparing query SELECT Songs.* 00001899 552.63922119 [48852] FROM Songs 00001900 552.63922119 [48852] WHERE Songs.id=361312 AND ((Songs.SongPath like '%\TV\%')) 00001901 552.63958740 [48852] 41140 DB lock finished, took 3601. 00001902 552.63970947 [48852] 41140 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001903 552.63977051 [48852] 41140 DB lock finished, took 167. 00001904 552.63995361 [48852] 41140 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001905 552.64001465 [48852] 41140 DB lock finished, took 174. 00001906 552.64099121 [48852] 41140 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001907 552.64105225 [48852] 41140 DB lock finished, took 166. 00001908 552.64123535 [48852] 41140 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001909 552.64135742 [48852] 41140 DB lock finished, took 151. 00001910 552.64227295 [48852] 41140 DB open SQL: SELECT Songs.* 00001911 552.64227295 [48852] FROM Songs 00001912 552.64227295 [48852] WHERE Songs.id=361312 AND ((Songs.SongPath like '%\Movies\%')) 00001913 552.64233398 [48852] OpenQuery - Preparing query SELECT Songs.* 00001914 552.64233398 [48852] FROM Songs 00001915 552.64233398 [48852] WHERE Songs.id=361312 AND ((Songs.SongPath like '%\Movies\%')) 00001916 552.64270020 [48852] 41140 DB lock finished, took 3549. 00001917 552.64282227 [48852] 41140 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001918 552.64294434 [48852] 41140 DB lock finished, took 170. 00001919 552.64306641 [48852] 41140 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001920 552.64318848 [48852] 41140 DB lock finished, took 139. 00001921 552.64392090 [48852] 41140 DB open SQL: SELECT * FROM Filters WHERE ID=? 00001922 552.64398193 [48852] 41140 DB lock finished, took 177. 00001923 552.64416504 [48852] 41140 DB open SQL: SELECT ID, Name, View FROM Views WHERE ID = ? 00001924 552.64422607 [48852] 41140 DB lock finished, took 120. 00001925 552.64489746 [48852] 41140 DB open SQL: SELECT Songs.* 00001926 552.64489746 [48852] FROM Songs 00001927 552.64489746 [48852] WHERE Songs.id=361312 AND (Songs.SongPath like '%\\lowlander04\Multimedia\Family Videos\%') AND NOT (Songs.SongPath like '%Plex%') 00001928 552.64501953 [48852] OpenQuery - Preparing query SELECT Songs.* 00001929 552.64501953 [48852] FROM Songs 00001930 552.64501953 [48852] WHERE Songs.id=361312 AND (Songs.SongPath like '%\\lowlander04\Multimedia\Family Videos\%') AND NOT (Songs.SongPath like '%Plex%') 00001931 552.64538574 [48852] 41140 DB lock finished, took 3712. 00001932 552.66101074 [48852] PrepareDockedVideo: Begin 00001933 552.66107178 [48852] PrepareDockedVideo: Switching=false IsStartingPlayback=false WasManuallyChanged=false 00001934 552.66107178 [48852] PrepareDockedVideo: Reduced window or audio 00001935 552.66107178 [48852] PrepareDockedVideo: Audio 00001936 552.66119385 [48852] PrepareDockedVideo: End 00001937 552.66772461 [48852] MM4 [49844] TImagePlus.Paint: start 00001938 552.73474121 [48852] MM4 [49844] TStretcher.PerformStretch: Threads[11], source[600, 545], target[352,319] 00001939 552.73638916 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001940 552.73699951 [48852] TIndyHTTP.GetResponseContent EXCEPTION!!! : HTTP/1.1 404 Not Found ,URL: http://lyrics.wikia.com/wiki/Bruce_Cockburn:Bearded_Folksinger, ResponseContent.Size: 0, ResponseCode: 404 00001941 552.73754883 [48852] BQ: Starting a new task. 00001942 552.73815918 [48852] BQ: There are threads waiting, resume one. 00001943 552.73870850 [48852] lyricsSearch.js: LoadWebPageFailed 00001944 552.73931885 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001945 552.73986816 [48852] lyricsSearch.js: whatNext continue 00001946 552.74047852 [48852] BQ: Starting a new task. 00001947 552.74102783 [48852] lyricsSearch.js: buildBruteForce 00001948 552.74157715 [48852] BQ: There are threads waiting, resume one. 00001949 552.74212646 [48852] lyricsSearch.js: Calling search send 00001950 552.74273682 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001951 552.74334717 [48852] lyricsSearch.js: SearchSend 00001952 552.74395752 [48852] BQ: Starting a new task. 00001953 552.74450684 [48852] BQ: There are threads waiting, resume one. 00001954 552.74511719 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001955 552.74572754 [48852] BQ: Starting a new task. 00001956 552.74633789 [48852] TIndyHTTP.GetResponseContent started: URL: http://www.seekalyric.com/song/Bruce_Cockburn/Bearded_Folksinger, RequestBody: 00001957 552.74713135 [48852] BQ: There are threads waiting, resume one. 00001958 552.74786377 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001959 552.74859619 [48852] BQ: Starting a new task. 00001960 552.75000000 [48852] BQ: Currently running 6 threads of 8 00001961 552.75073242 [48852] BQ: Starting a new thread. 00001962 552.78228760 [48852] TGenThread.Create: ThreadName: BackgroundQueue , Running Threads: Internal: 6, All: 47 00001963 552.78808594 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001964 552.78808594 [48852] BQ: Starting a new task. 00001965 552.78814697 [48852] BQ: There are threads waiting, resume one. 00001966 552.78814697 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001967 552.78814697 [48852] BQ: Starting a new task. 00001968 552.78820801 [48852] BQ: There are threads waiting, resume one. 00001969 552.78820801 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001970 552.78826904 [48852] BQ: Starting a new task. 00001971 552.78833008 [48852] BQ: There are threads waiting, resume one. 00001972 552.78833008 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001973 552.78839111 [48852] BQ: Starting a new task. 00001974 552.78839111 [48852] BQ: There are threads waiting, resume one. 00001975 552.78845215 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001976 552.78845215 [48852] BQ: Starting a new task. 00001977 552.78845215 [48852] BQ: There are threads waiting, resume one. 00001978 552.78857422 [48852] MM4 [49844] TStretcher.PerformStretch: Finished 00001979 552.78912354 [48852] MM4 [49844] TImagePlus.Paint: finished 00001980 552.79052734 [48852] Thread 'BackgroundQueue' has started 46076 00001981 553.19409180 [48852] TGenThread.Create: ThreadName: _ManageTransactions , Running Threads: Internal: 7, All: 46 00001982 553.20025635 [48852] BQ: Added new task. Currently 1 tasks in queue. 00001983 553.20025635 [48852] BQ: Starting a new task. 00001984 553.20025635 [48852] BQ: There are threads waiting, resume one. 00001985 553.20037842 [48852] 52248 DB open SQL: SELECT Songs.ID FROM Songs WHERE ( Songs.TrackType in (4) ) LIMIT 1 00001986 553.20056152 [48852] 52248 DB lock finished, took 544. 00001987 553.20330811 [48852] Thread '_ManageTransactions' has started 41212 00001988 553.20343018 [48852] Going '_ManageTransactions'to make final callback 41212 00001989 553.20349121 [48852] Thread '_ManageTransactions'has finished 41212 00001990 553.20886230 [48852] WASAPI: Stopped. 00001991 553.20892334 [48852] WASAPI: New track not starting, finishing playback thread. 00001992 553.23083496 [48852] WASAPI: Output thread is terminating 00001993 553.23089600 [48852] WASAPI: Output thread is terminated 00001994 553.28448486 [48852] TIndyHTTP.GetResponseContent finished: URL: http://www.seekalyric.com/song/Bruce_Cockburn/Bearded_Folksinger, ResponseContent.Size: 25143, ResponseCode: 200 00001995 553.31878662 [48852] lyricsSearch.js: LoadedWebPage 00001996 553.31970215 [48852] lyricsSearch.js: whatNext continue 00001997 553.31976318 [48852] lyricsSearch.js: Calling search send 00001998 553.31988525 [48852] lyricsSearch.js: SearchSend 00001999 553.32141113 [48852] TIndyHTTP.GetResponseContent started: URL: http://www.elyrics.net/read/b/bruce-cockburn-lyrics/bearded-folksinger-lyrics.html, RequestBody: 00002000 553.87707520 [48852] TIndyHTTP.GetResponseContent EXCEPTION!!! : HTTP/1.1 404 Not Found ,URL: http://www.elyrics.net/read/b/bruce-cockburn-lyrics/bearded-folksinger-lyrics.html, ResponseContent.Size: 0, ResponseCode: 404 00002001 553.87847900 [48852] lyricsSearch.js: LoadWebPageFailed 00002002 553.87860107 [48852] lyricsSearch.js: whatNext continue 00002003 553.87866211 [48852] lyricsSearch.js: Calling search send 00002004 553.87872314 [48852] lyricsSearch.js: SearchSend 00002005 553.88055420 [48852] TIndyHTTP.GetResponseContent started: URL: http://www.metrolyrics.com/bearded-folksinger-lyrics-bruce-cockburn.html, RequestBody: 00002006 554.79528809 [48852] TIndyHTTP.GetResponseContent finished: URL: http://www.metrolyrics.com/bearded-folksinger-lyrics-bruce-cockburn.html, ResponseContent.Size: 114704, ResponseCode: 200 00002007 554.92938232 [48852] lyricsSearch.js: LoadedWebPage 00002008 554.92993164 [48852] lyricsSearch.js: whatNext continue 00002009 554.92999268 [48852] lyricsSearch.js: Calling search send 00002010 554.93005371 [48852] lyricsSearch.js: SearchSend 00002011 554.93151855 [48852] TIndyHTTP.GetResponseContent started: URL: http://www.lyricsmode.com/lyrics/b/bruce_cockburn/bearded_folksinger.html, RequestBody: 00002012 555.18463135 [48852] TGenThread.Create: ThreadName: _ManageTransactions , Running Threads: Internal: 7, All: 44 00002013 555.19262695 [48852] Thread '_ManageTransactions' has started 51516 00002014 555.19274902 [48852] Going '_ManageTransactions'to make final callback 51516 00002015 555.19281006 [48852] Thread '_ManageTransactions'has finished 51516 00002016 555.69927979 [48852] TIndyHTTP.GetResponseContent EXCEPTION!!! : HTTP/1.1 404 Not Found ,URL: http://www.lyricsmode.com/lyrics/b/bruce_cockburn/bearded_folksinger.html, ResponseContent.Size: 0, ResponseCode: 404 00002017 555.70074463 [48852] lyricsSearch.js: LoadWebPageFailed 00002018 555.70086670 [48852] lyricsSearch.js: whatNext continue 00002019 555.70092773 [48852] lyricsSearch.js: Calling search send 00002020 555.70104980 [48852] lyricsSearch.js: SearchSend 00002021 555.70275879 [48852] TIndyHTTP.GetResponseContent started: URL: http://www.songcoleta.com/lyrics/Bearded_Folksinger_(Bruce_Cockburn), RequestBody: 00002022 555.78961182 [48852] Going 'BackgroundQueue'to make final callback 46076 00002023 555.78967285 [48852] Going 'BackgroundQueue'to make final callback 51052 00002024 555.78979492 [48852] Going 'BackgroundQueue'to make final callback 30196 00002025 555.78985596 [48852] Going 'BackgroundQueue'to make final callback 44212 00002026 555.78991699 [48852] Going 'BackgroundQueue'to make final callback 50380 00002027 555.78997803 [48852] Thread 'BackgroundQueue'has finished 46076 00002028 555.79010010 [48852] Thread 'BackgroundQueue'has finished 51052 00002029 555.79010010 [48852] Thread 'BackgroundQueue'has finished 30196 00002030 555.79016113 [48852] Thread 'BackgroundQueue'has finished 44212 00002031 555.79022217 [48852] Thread 'BackgroundQueue'has finished 50380 00002032 555.82086182 [48852] Going 'BackgroundQueue'to make final callback 12412 00002033 555.82092285 [48852] Thread 'BackgroundQueue'has finished 12412 00002034 556.21142578 [48852] Going 'BackgroundQueue'to make final callback 52248 00002035 556.21148682 [48852] DB: Deleting prepared query: SELECT Songs.* FROM Songs WHERE Songs.IDMedia=? AND Songs.SongPath=? 00002036 556.21173096 [48852] Thread 'BackgroundQueue'has finished 52248 00002037 556.22515869 [48852] TIndyHTTP.GetResponseContent EXCEPTION!!! : HTTP/1.1 404 NOT FOUND ,URL: http://www.songcoleta.com/lyrics/Bearded_Folksinger_(Bruce_Cockburn), ResponseContent.Size: 0, ResponseCode: 404 00002038 556.22637939 [48852] lyricsSearch.js: LoadWebPageFailed 00002039 556.22650146 [48852] lyricsSearch.js: whatNext continue 00002040 556.22662354 [48852] lyricsSearch.js: Calling search send 00002041 556.22668457 [48852] lyricsSearch.js: SearchSend 00002042 556.22875977 [48852] TIndyHTTP.GetResponseContent started: URL: http://lyrics.wikia.com/wiki/Various:Bearded_Folksinger, RequestBody: 00002043 556.54193115 [48852] TIndyHTTP.GetResponseContent EXCEPTION!!! : HTTP/1.1 404 Not Found ,URL: http://lyrics.wikia.com/wiki/Various:Bearded_Folksinger, ResponseContent.Size: 0, ResponseCode: 404 00002044 556.54315186 [48852] lyricsSearch.js: LoadWebPageFailed 00002045 556.54321289 [48852] lyricsSearch.js: whatNext continue 00002046 556.54333496 [48852] lyricsSearch.js: Calling search send 00002047 556.54345703 [48852] lyricsSearch.js: SearchSend 00002048 556.54510498 [48852] TIndyHTTP.GetResponseContent started: URL: http://www.seekalyric.com/song/Various/Bearded_Folksinger, RequestBody: 00002049 557.01873779 [48852] TIndyHTTP.GetResponseContent finished: URL: http://www.seekalyric.com/song/Various/Bearded_Folksinger, ResponseContent.Size: 24734, ResponseCode: 200 00002050 557.04522705 [48852] lyricsSearch.js: LoadedWebPage 00002051 557.04528809 [48852] lyricsSearch.js: whatNext continue 00002052 557.04534912 [48852] lyricsSearch.js: Calling search send 00002053 557.04541016 [48852] lyricsSearch.js: SearchSend 00002054 557.04614258 [48852] TIndyHTTP.GetResponseContent started: URL: http://www.elyrics.net/read/v/various-lyrics/bearded-folksinger-lyrics.html, RequestBody: 00002055 557.18365479 [48852] TGenThread.Create: ThreadName: _ManageTransactions , Running Threads: Internal: 0, All: 45 00002056 557.19390869 [48852] Thread '_ManageTransactions' has started 51928 00002057 557.19396973 [48852] DB: COMMIT transaction 00002058 557.20501709 [48852] Going '_ManageTransactions'to make final callback 51928 00002059 557.20526123 [48852] Thread '_ManageTransactions'has finished 51928 00002060 557.58300781 [48852] TIndyHTTP.GetResponseContent EXCEPTION!!! : HTTP/1.1 404 Not Found ,URL: http://www.elyrics.net/read/v/various-lyrics/bearded-folksinger-lyrics.html, ResponseContent.Size: 0, ResponseCode: 404 00002061 557.58441162 [48852] lyricsSearch.js: LoadWebPageFailed 00002062 557.58447266 [48852] lyricsSearch.js: whatNext continue 00002063 557.58459473 [48852] lyricsSearch.js: Calling search send 00002064 557.58471680 [48852] lyricsSearch.js: SearchSend 00002065 557.58642578 [48852] TIndyHTTP.GetResponseContent started: URL: http://www.metrolyrics.com/bearded-folksinger-lyrics-various.html, RequestBody: 00002066 557.89532471 [48852] TIndyHTTP.GetResponseContent finished: URL: http://www.metrolyrics.com/bearded-folksinger-lyrics-various.html, ResponseContent.Size: 86992, ResponseCode: 200 00002067 558.00152588 [48852] lyricsSearch.js: LoadedWebPage 00002068 558.00189209 [48852] lyricsSearch.js: whatNext continue 00002069 558.00201416 [48852] lyricsSearch.js: Calling search send 00002070 558.00213623 [48852] lyricsSearch.js: SearchSend 00002071 558.00354004 [48852] TIndyHTTP.GetResponseContent started: URL: http://www.lyricsmode.com/lyrics/v/various/bearded_folksinger.html, RequestBody: 00002072 558.75231934 [48852] TIndyHTTP.GetResponseContent EXCEPTION!!! : HTTP/1.1 404 Not Found ,URL: http://www.lyricsmode.com/lyrics/v/various/bearded_folksinger.html, ResponseContent.Size: 0, ResponseCode: 404 00002073 558.75366211 [48852] lyricsSearch.js: LoadWebPageFailed 00002074 558.75378418 [48852] lyricsSearch.js: whatNext continue 00002075 558.75390625 [48852] lyricsSearch.js: Calling search send 00002076 558.75396729 [48852] lyricsSearch.js: SearchSend 00002077 558.75561523 [48852] TIndyHTTP.GetResponseContent started: URL: http://www.songcoleta.com/lyrics/Bearded_Folksinger_(Various), RequestBody: 00002078 559.21081543 [48852] TIndyHTTP.GetResponseContent EXCEPTION!!! : HTTP/1.1 404 NOT FOUND ,URL: http://www.songcoleta.com/lyrics/Bearded_Folksinger_(Various), ResponseContent.Size: 0, ResponseCode: 404 00002079 559.21197510 [48852] lyricsSearch.js: LoadWebPageFailed 00002080 559.21209717 [48852] lyricsSearch.js: whatNext continue 00002081 559.21215820 [48852] lyricsSearch.js: whatNext continue failed 1 00002082 559.21228027 [48852] lyricsSearch.js: whatNext continue null result 00002083 559.21240234 [48852] Events: Destroying TScriptExec: D:\Software\MediaMonkey\Scripts\lyricsSearch.js 00002084 559.21307373 [48852] Going 'SearchLyricsOnBackgroud_Var'to make final callback 52324 00002085 559.21356201 [48852] MM4 [49844] TLyricsScroller.createOverlay: rows: 2 00002086 559.21429443 [48852] MM4 [49844] TLyricsScroller.createOverlay: finished 00002087 559.21441650 [48852] MM4 [49844] TLyricsScroller.createOverlay: rows: 2 00002088 559.21563721 [48852] MM4 [49844] TLyricsScroller.createOverlay: finished 00002089 559.21612549 [48852] MM4 [49844] TImagePlus.Paint: start 00002090 559.21661377 [48852] MM4 [49844] TImagePlus.Paint: finished 00002091 559.25183105 [48852] Thread 'SearchLyricsOnBackgroud_Var'has finished 52324 00002092 565.93646240 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 0, All: 37 00002093 565.94232178 [48852] PostponeComputerSleep: Enabled = 0 00002094 565.94537354 [48852] Thread 'UpdateDriveLetters_Var' has started 48188 00002095 565.94543457 [48852] >UpdateDriveLetters - start< 00002096 565.97558594 [48852] >UpdateDriveLetters - end< 00002097 565.97564697 [48852] Going 'UpdateDriveLetters_Var'to make final callback 48188 00002098 565.97576904 [48852] Thread 'UpdateDriveLetters_Var'has finished 48188 00002099 595.94262695 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 0, All: 37 00002100 595.94830322 [48852] PostponeComputerSleep: Enabled = 0 00002101 595.95068359 [48852] Thread 'UpdateDriveLetters_Var' has started 4508 00002102 595.95074463 [48852] >UpdateDriveLetters - start< 00002103 595.96582031 [48852] >UpdateDriveLetters - end< 00002104 595.96588135 [48852] Going 'UpdateDriveLetters_Var'to make final callback 4508 00002105 595.96594238 [48852] Thread 'UpdateDriveLetters_Var'has finished 4508 00002106 625.94470215 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 0, All: 36 00002107 625.95343018 [48852] PostponeComputerSleep: Enabled = 0 00002108 625.95605469 [48852] Thread 'UpdateDriveLetters_Var' has started 49164 00002109 625.95617676 [48852] >UpdateDriveLetters - start< 00002110 625.97235107 [48852] >UpdateDriveLetters - end< 00002111 625.97241211 [48852] Going 'UpdateDriveLetters_Var'to make final callback 49164 00002112 625.97253418 [48852] Thread 'UpdateDriveLetters_Var'has finished 49164 00002113 655.95446777 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 0, All: 34 00002114 655.96118164 [48852] PostponeComputerSleep: Enabled = 0 00002115 655.96295166 [48852] Thread 'UpdateDriveLetters_Var' has started 31056 00002116 655.96301270 [48852] >UpdateDriveLetters - start< 00002117 655.97839355 [48852] >UpdateDriveLetters - end< 00002118 655.97845459 [48852] Going 'UpdateDriveLetters_Var'to make final callback 31056 00002119 655.97857666 [48852] Thread 'UpdateDriveLetters_Var'has finished 31056 00002120 685.93597412 [48852] TGenThread.Create: ThreadName: UpdateDriveLetters_Var , Running Threads: Internal: 0, All: 34 00002121 685.94207764 [48852] PostponeComputerSleep: Enabled = 0 00002122 685.94427490 [48852] Thread 'UpdateDriveLetters_Var' has started 22948 00002123 685.94439697 [48852] >UpdateDriveLetters - start< 00002124 685.95721436 [48852] >UpdateDriveLetters - end< 00002125 685.95721436 [48852] Going 'UpdateDriveLetters_Var'to make final callback 22948 00002126 685.95727539 [48852] Thread 'UpdateDriveLetters_Var'has finished 22948