High CPU Usage

[giggio]

Describe the bug/issue
Flow is sometimes using 1 to 5% CPU when it is not being used. It is not clear why this is happening. It stopped after a while.

I have taken a full memory dump from the process and will try to analyze it, if I find more info I'll comment here.

To Reproduce
Steps to reproduce the behavior:
I can't find a way to replicate the behavior, it happens intermittently.

Screenshots
N/A

Your System

Windows build number: Version 10.0.19041.388
Flow Launcher version: 1.1.2

Flow Launcher Error Log

I have found exceptions when that was happening. It seems it was indexing a file at the OneDrive for business folder. I have changed the folder in the logs to <filename>, as the file name and path are sensitive. I don't think this is related (see the dumps later on the comments).

2020-07-27 11:10:15.2840|ERROR|ImageLoader.Load|-------------------------- Begin exception --------------------------
2020-07-27 11:10:15.2840|ERROR|ImageLoader.Load|Failed to get thumbnail for <filename> on second try
2020-07-27 11:10:15.3018|ERROR|ImageLoader.Load|Exception full name:
 <System.Runtime.InteropServices.COMException>
2020-07-27 11:10:15.3018|ERROR|ImageLoader.Load|Exception message:
 <Error while extracting thumbnail for <filename>>
2020-07-27 11:10:15.3212|ERROR|ImageLoader.Load|Exception stack trace:
 <   at Flow.Launcher.Infrastructure.Image.WindowsThumbnailProvider.GetHBitmap(String fileName, Int32 width, Int32 height, ThumbnailOptions options) in C:\Workbench\Git\Flow.Launcher\Flow.Launcher.Infrastructure\Image\ThumbnailReader.cs:line 150
   at Flow.Launcher.Infrastructure.Image.WindowsThumbnailProvider.GetThumbnail(String fileName, Int32 width, Int32 height, ThumbnailOptions options) in C:\Workbench\Git\Flow.Launcher\Flow.Launcher.Infrastructure\Image\ThumbnailReader.cs:line 109
   at Flow.Launcher.Infrastructure.Image.ImageLoader.GetThumbnail(String path, ThumbnailOptions option) in C:\Workbench\Git\Flow.Launcher\Flow.Launcher.Infrastructure\Image\ImageLoader.cs:line 209
   at Flow.Launcher.Infrastructure.Image.ImageLoader.GetThumbnailResult(String& path, Boolean loadFullImage) in C:\Workbench\Git\Flow.Launcher\Flow.Launcher.Infrastructure\Image\ImageLoader.cs:line 184
   at Flow.Launcher.Infrastructure.Image.ImageLoader.LoadInternal(String path, Boolean loadFullImage) in C:\Workbench\Git\Flow.Launcher\Flow.Launcher.Infrastructure\Image\ImageLoader.cs:line 135>
2020-07-27 11:10:15.3376|ERROR|ImageLoader.Load|Exception source:
 <Flow.Launcher.Infrastructure>
2020-07-27 11:10:15.3526|ERROR|ImageLoader.Load|Exception target site:
 <IntPtr GetHBitmap(System.String, Int32, Int32, Flow.Launcher.Infrastructure.Image.ThumbnailOptions)>
2020-07-27 11:10:15.3648|ERROR|ImageLoader.Load|Exception HResult:
 <-2147467259>
2020-07-27 11:10:15.3764|ERROR|ImageLoader.Load|Exception full name:
 <System.Runtime.InteropServices.COMException>
2020-07-27 11:10:15.3764|ERROR|ImageLoader.Load|Exception message:
 <0x8004B205>
2020-07-27 11:10:15.4015|ERROR|ImageLoader.Load|Exception stack trace:
 <>
2020-07-27 11:10:15.4161|ERROR|ImageLoader.Load|Exception source:
 <>
2020-07-27 11:10:15.4306|ERROR|ImageLoader.Load|Exception target site:
 <>
2020-07-27 11:10:15.4447|ERROR|ImageLoader.Load|Exception HResult:
 <-2147175931>
2020-07-27 11:10:15.4572|ERROR|ImageLoader.Load|-------------------------- End exception --------------------------

[giggio]

Ok, from the dump, this is what the main runaway thread was doing:

0:000> !clrstack
OS Thread Id: 0x3998 (0)
        Child SP               IP Call Site
00000003281DE148 00007ff999bb1104 [InlinedCallFrame: 00000003281de148] MS.Win32.UnsafeNativeMethods.IntGetMessageW(System.Windows.Interop.MSG ByRef, System.Runtime.InteropServices.HandleRef, Int32, Int32)
00000003281DE148 00007ff8e9eea824 [InlinedCallFrame: 00000003281de148] MS.Win32.UnsafeNativeMethods.IntGetMessageW(System.Windows.Interop.MSG ByRef, System.Runtime.InteropServices.HandleRef, Int32, Int32)
00000003281DE120 00007ff8e9eea824 ILStubClass.IL_STUB_PInvoke(System.Windows.Interop.MSG ByRef, System.Runtime.InteropServices.HandleRef, Int32, Int32)
00000003281DE1E0 00007ff8eac25561 MS.Win32.UnsafeNativeMethods.GetMessageW(System.Windows.Interop.MSG ByRef, System.Runtime.InteropServices.HandleRef, Int32, Int32) [/_/src/Microsoft.DotNet.Wpf/src/shared/MS/Win32/UnsafeNativeMethodsCLR.cs @ 1245]
00000003281DE220 00007ff8eac253b1 System.Windows.Threading.Dispatcher.GetMessage(System.Windows.Interop.MSG ByRef, IntPtr, Int32, Int32) [/_/src/Microsoft.DotNet.Wpf/src/WindowsBase/System/Windows/Threading/Dispatcher.cs @ 2216]
00000003281DE2B0 00007ff94775a225 System.Windows.Threading.Dispatcher.PushFrameImpl(System.Windows.Threading.DispatcherFrame) [/_/src/Microsoft.DotNet.Wpf/src/WindowsBase/System/Windows/Threading/Dispatcher.cs @ 2134]
00000003281DE340 00007ff947757801 System.Windows.Threading.Dispatcher.PushFrame(System.Windows.Threading.DispatcherFrame) [/_/src/Microsoft.DotNet.Wpf/src/WindowsBase/System/Windows/Threading/Dispatcher.cs @ 331]
00000003281DE370 00007ff9477577ae System.Windows.Threading.Dispatcher.Run() [/_/src/Microsoft.DotNet.Wpf/src/WindowsBase/System/Windows/Threading/Dispatcher.cs @ 299]
00000003281DE3A0 00007ff947f6e9dc System.Windows.Application.RunDispatcher(System.Object) [/_/src/Microsoft.DotNet.Wpf/src/PresentationFramework/System/Windows/Application.cs @ 2403]
00000003281DE3D0 00007ff947f6cff1 System.Windows.Application.RunInternal(System.Windows.Window) [/_/src/Microsoft.DotNet.Wpf/src/PresentationFramework/System/Windows/Application.cs @ 1694]
00000003281DE420 00007ff947f69fcc System.Windows.Application.Run() [/_/src/Microsoft.DotNet.Wpf/src/PresentationFramework/System/Windows/Application.cs @ 198]
00000003281DE450 00007ff8e97912b3 Flow.Launcher.App.Main() [C:\Workbench\Git\Flow.Launcher\Flow.Launcher\App.xaml.cs @ 42]
00000003281DE688 00007ff9492a6b93 [GCFrame: 00000003281de688] 
00000003281DEC30 00007ff9492a6b93 [GCFrame: 00000003281dec30] 

It points to App.xaml.cs, here:

Flow.Launcher/Flow.Launcher/App.xaml.cs

Line 42 in 8a9c338

application.Run();

The second thread, which had much less usage, showed exactly the same stack. These are the first 4 runaway threads, clearly the first two are doing most of the work:

0:000> !runaway
 User Mode Time
  Thread       Time
    0:3998     0 days 0:03:58.000
    9:1f44     0 days 0:00:38.187
    2:39f0     0 days 0:00:01.625
    7:41b0     0 days 0:00:00.046

It seems that it is working on the message loop with GetMessageW. I'm not sure why that would be using so much CPU.

[giggio]

Ok, I just restarted the app and ran another 2 dumps. The application consistently runs with some CPU (from 1% to 3%) for a while, and then goes to sleep, staying at 0.01% CPU. Both dumps showed exactly the same stack.

I'm not getting the exceptions since the restart, so the exception on the issue description is probably unrelated.

[jjw24]

Hey this memory and high cpu issue is a common issue that also exists for PT Run and Wox. PT Run has shared the fix and I will implement the fix soon.

[giggio]

@jjw24 Interesting. What causes it?

[jjw24]

So there are two main issues. Memory is partially caused by result list's image caching and implementation of INotifyPropertyChanged on ContextMenu items, and possible more memory leaks which is still under investigation by our friends at PT Run. CPU issue maybe caused by image caching during the loading of results so will see how it is after implementing the partial fix of memory issue. I will have to take another look at the CPU issue happening over at PT Run because I suspect that issue does not apply to Flow since we have not implemented a program watcher.

[taooceros]

How's going now?

[giggio]

I just checked and noticed that the peak CPU usage on start is not happening anymore.
Memory is fine, around 135MB, which is acceptable.
Flow still stays at 0.6% of CPU even when not doing anything, which is weird. Souldn't it be idle until we request it?

[taooceros]

Wox has provided a fix toward the slight CPU usage due to progress bar animation. Not sure if that's the reason, but I will try porting it.

[taooceros]

@giggio https://ci.appveyor.com/api/buildjobs/31faqy2whi9ua5yj/artifacts/Output%2FPackages%2FFlow-Launcher-v1.7.0.exe
Take a try.

[giggio]

Just installed it. It made no difference.
I was already on 1.7.0, because I tested the plugin priority feature. Are we sure it installed the new version?

[giggio]

I looked at date/time properties of the binaries. They are correct, showing the files were created 5 minutes ago. So I guess the update worked, but I still get about 1% of CPU usage all the time.