Bug 104031 - CPU usage when hovering over Start Center buttons
Summary: CPU usage when hovering over Start Center buttons
Status: NEW
Alias: None
Product: LibreOffice
Classification: Unclassified
Component: LibreOffice (show other bugs)
Version:
(earliest affected)
5.0.0.5 release
Hardware: All All
: medium normal
Assignee: Not Assigned
URL:
Whiteboard:
Keywords: bibisected, perf, regression
Depends on:
Blocks: Main-Loop
  Show dependency treegraph
 
Reported: 2016-11-19 14:09 UTC by Telesto
Modified: 2018-08-17 19:02 UTC (History)
1 user (show)

See Also:
Crash report or crash signature:


Attachments
CPU Usage hovering Start Center (5.62 MB, video/quicktime)
2016-11-19 14:09 UTC, Telesto
Details
LLDB Backtrace (644.34 KB, text/plain)
2016-11-19 14:17 UTC, Telesto
Details
Process Monitor Output LO5400 (16.77 KB, application/vnd.oasis.opendocument.spreadsheet)
2016-12-14 17:21 UTC, Telesto
Details
SAL_LOG=+TIMESTAMP+INFO,+WARN (53.81 KB, application/vnd.oasis.opendocument.spreadsheet)
2016-12-15 14:04 UTC, Telesto
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Telesto 2016-11-19 14:09:00 UTC
Description:
When hovering over Start Center buttons the CPU usage increases significantly.


Steps to Reproduce:
1. Start LibreOffice
2. Hoover over Start Center buttons

Actual Results:  
CPU usage increased to around 25%

Expected Results:
Constant CPU usage around 2%


Reproducible: Always

User Profile Reset: YES

Additional Info:
Version: 5.3.0.0.alpha1+
Build ID: 074f0ab1d76f16fe92493868e2f2de75e67792ef
CPU Threads: 4; OS Version: Mac OS X 10.12.1; UI Render: default; Layout Engine: new; 
TinderBox: MacOSX-x86_64@49-TDF, Branch:master, Time: 2016-11-15_00:29:07
Locale: en-US (en_US.UTF-8); Calc: group


User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_1) AppleWebKit/602.2.14 (KHTML, like Gecko) Version/10.0.1 Safari/602.2.14
Comment 1 Telesto 2016-11-19 14:09:34 UTC
Created attachment 128869 [details]
CPU Usage hovering Start Center
Comment 2 Telesto 2016-11-19 14:17:30 UTC
Created attachment 128870 [details]
LLDB Backtrace

Version: 5.3.0.0.alpha1+
Build ID: 074f0ab1d76f16fe92493868e2f2de75e67792ef
CPU Threads: 4; OS Version: Mac OS X 10.12.1; UI Render: default; Layout Engine: new; 
TinderBox: MacOSX-x86_64@49-TDF, Branch:master, Time: 2016-11-15_00:29:07
Locale: en-US (en_US.UTF-8); Calc: group
Comment 3 Telesto 2016-11-19 14:18:31 UTC
LLDB debug information contains a warning:
@"WARNING: nextEventMatchingMask should only be called from the Main Thread! This will throw an exception in the future."
Comment 4 Telesto 2016-11-19 16:11:32 UTC
Within the backtrace I noticed:
- @"AppKit cannot convert carbon event class '%.4s' to CGEventRef."
- @"AppKit cannot convert carbon mouse event of kind '%ld' to CGEventRef."
- @"AppKit cannot convert carbon mouse events of button '%ld' to CGEventRef."
- @"WARNING: nextEventMatchingMask should only be called from the Main Thread! This will throw an exception in the future."
- THE_PROCESS_HAS_FORKED_AND_YOU_CANNOT_USE_THIS_COREFOUNDATION_FUNCTIONALITY___YOU_MUST_EXEC__
Comment 5 Alex Thurgood 2016-11-21 09:41:27 UTC
Confirming with

Version: 5.3.0.0.alpha1+
Build ID: e1af58c1260f442c2731ae8a705deba732246b1d
CPU Threads: 2; OS Version: Mac OS X 10.12.1; UI Render: default; Layout Engine: new; 
Locale: fr-FR (fr_FR.UTF-8); Calc: group
Comment 6 Alex Thurgood 2016-11-21 09:50:52 UTC
I don't see a hike as great as you indicate, but if one hovers the mouse over each icon in turn at approximately half a second per icon, processor usage shoots up to about 15% - still a performance problem though, as the app should be idling at around 0,2-0,5 %


I also noted that the first time after app launch that you click on the Template icon arrow to display the dropdown list, processor usage spikes to nearly 100% and remains there until the mouse moves over another icon.
Comment 7 Telesto 2016-11-21 10:53:24 UTC
A more complete list of possible causes:

CoreFoundation`_CFXNotificationPost:
@"*** attempt to post distributed notification '%s' thwarted by sandboxing.%s%s"\
__THE_PROCESS_HAS_FORKED_AND_YOU_CANNOT_USE_THIS_COREFOUNDATION_FUNCTIONALITY___YOU_MUST_EXEC__\

CoreFoundation`__CFRunLoopRun:\
"Unable to get port for run loop mode queue (%d)"\

CoreFoundation`CFRunLoopRunSpecific:
__THE_PROCESS_HAS_FORKED_AND_YOU_CANNOT_USE_THIS_COREFOUNDATION_FUNCTIONALITY___YOU_MUST_EXEC__\

AppKit`_DPSNextEvent:\
@"still in loop, timeout = %f seconds"\
@"got apple event of class %lx, ID %x"\
@"<Unknown Function>"\
@"<Unknown File>"\
@"Could not alloc empty CGEvent"\
@"AppKit cannot convert carbon event class '%.4s' to CGEventRef."\
@"AppKit cannot convert carbon mouse event of kind '%ld' to CGEventRef."\
@"AppKit cannot convert carbon mouse events of button '%ld' to CGEventRef."\
@"got unrecognized event, eventClass is %x, eventKind is %d"\
@"found event in concurrent event queue, looping around to get it"\
@"Force event behavior:%d"\
@"Received event: %@"\

NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:]:\
@"WARNING: nextEventMatchingMask should only be called from the Main Thread! This will throw an exception in the future."\

AppKit`-[NSApplication run]:\
@"<Unknown File>"\
@"NSApp with wrong _running count"\
@"No Info.plist file in application bundle or no NSPrincipalClass in the Info.plist file, exiting"\
@"Unable to find class: %@, exiting"\
@"Unable to load storyboard file: %@, exiting"\
@"Initial Storyboard controller is neither a NSWindowController nor a NSViewController: %@, from %@"\
@"Unable to find class: %@, exiting"\
@"Unable to load storyboard file: %@, exiting"\
@"Unable to load nib file: %@, exiting"\
@"No DelegateClass specfied in info dictionary, exiting"\
@"No NSMainNibFile or NSMainStoryboardFile specified in info dictionary, exiting"\

libvcllo.dylib`ImplSVMainHook:\
@"%@/Library/Saved Application State/%s.savedState/restorecount.plist"\
@"%@/Library/Saved Application State/%s.savedState/restorecount.txt"\
Comment 8 Telesto 2016-12-11 18:51:04 UTC
Isn't a MacOS only issue. Windows is also affected.

Found in:
Version: 5.4.0.0.alpha0+
Build ID: 84f2ff67a7e404febf710b1dc7f66d06745c503f
CPU Threads: 4; OS Version: Windows 6.19; UI Render: GL; 
TinderBox: Win-x86@42, Branch:master, Time: 2016-12-09_23:20:01
Locale: nl-NL (nl_NL); Calc: CL

and in
Version: 5.0.0.5
Build ID: 1b1a90865e348b492231e1c451437d7a15bb262b
Locale: en-US (nl_NL)

but not in:
Versie: 4.4.6.3 
Build ID: e8938fd3328e95dcf59dd64e7facd2c7d67c704d
Locale: nl_NL

CPU increase is a bit lower though: around 8% (maybe system depended)
Comment 9 Telesto 2016-12-14 17:21:13 UTC
Created attachment 129642 [details]
Process Monitor Output LO5400

Process Monitor Output
Comment 10 Telesto 2016-12-14 17:24:52 UTC
@Buovjaga:
Would you take a look at the process monitor output. Seems LibO is search for a helpfile... QueryDirectory	C:\Program Files (x86)\LibreOfficeDev 5\help\en	NO SUCH FILE	Filter: en
Comment 11 Telesto 2016-12-15 14:04:47 UTC
Created attachment 129669 [details]
SAL_LOG=+TIMESTAMP+INFO,+WARN

SAL_LOG Launching and hovering over Start Center
Version: 5.4.0.0.alpha0+
Build ID: d538d3d84172a74dfe97d59a6d3daf9a45459cab
CPU Threads: 4; OS Version: Windows 6.19; UI Render: default; 
TinderBox: Win-x86@39, Branch:master, Time: 2016-12-14_00:28:59
Locale: nl-NL (nl_NL); Calc: CL
Comment 12 QA Administrators 2018-03-24 03:31:44 UTC Comment hidden (obsolete)
Comment 13 Buovjaga 2018-06-05 17:02:51 UTC
Bibisected with win 5.0 repo to range https://cgit.freedesktop.org/libreoffice/core/log/?qt=range&q=9b4abcd1c45a646a1ac9120fe1c489ba6bb44e95...e6e8a060ecc6e4fd51cfe88e00d841d546ed5915
Tobias Madl's timer, idle & scheduling work seems to be the cause.
Won't bother adding to CC as he has not committed anything since 2015.
Adding stuff to See also that mention 9b4abcd1c45a646a1ac9120fe1c489ba6bb44e95