Created attachment 128344 [details]
Xcode Instruments Memory Allocation full list

Created attachment 128345 [details]
Assembly Information around the malloc

There need to be a saved (default) profile for the bug to occur.

Created attachment 128463 [details]
export SAL_LOG=+INFO,+WARN

Export SAL_LOG=+INFO,+WARN when minimising on MacOS Sierra 10.12.1 with LO 5.3.0.0.alpha0+
Build ID: a9afa89e953f0f32acf26b143717e7d067cbc75a
CPU Threads: 4; OS Version: Mac OS X 10.12.1; UI Render: default; 
TinderBox: MacOSX-x86_64@49-TDF, Branch:master, Time: 2016-10-13_05:13:57
Locale: nl-NL (nl_NL.UTF-8); Calc: group

Confirming.

1) Opened 15 blank documents in LO Writer 5212 OSX 10.12
2) Minimized three of the document windows.
3) LO application becomes unresponsive, even when switching contexts (Space switching) or clicking on other app windows and back to LO app windows.

The problem isn't specific for a MacOS version. I found it in Mavericks, Yosemite and Sierra (I didn't test El Capitan). The problem is most noticeable since LO 4.4.0.0 and up. Prior, with LO 4.3.7.2, there is just a small hick-up (+/-5 sec) when minimising one or two screens out of 30.

Hi Telesto - its great to have your RTF documents with log fragments inside a zip file - but up-loading an ODT or DOCX would be more helpful (and is already compressed / zipped ;-).

Your log seems to be very long on churning debug around langtag and rendering - you can expect a dbgutil build to work rather more hard.

I don't believe the race mentioned in svapp.cxx has anything to do with this FWIW. Of course - hard to do anything without a Mac.

Prolly a better way to find what is going on - is to break in the debugger and step through what is happening in this long delay. The trace suggests we are doing something silly with fonts - almost certainly re-populating / rendering the font pop-downs (perhaps in each window) for a rather large set of fonts.

Would be great to have an xcode trace (with debugging symbols - ie. unless you see CXX files and line numbers in the trace it has not got debugging symbols) - during the slowness.

Created attachment 128570 [details]
LLDB output

I don't really know my way around in LLDB (novice), and the start of the backtrace is somewhat random but seems to contain some relevant information.

Created attachment 128576 [details]
LLDB backtrace

This LLDB backtrace seems the contain the problem.

Ah - so the top of the trace shows that it is taking time in dumping debugging information to a stream (the SAL_LOG stuff) - which is done whether or not we actually end up logging that.

Might be good to continue  and break things a few times through the delay - to see what is going on and consuming the time =)

Interesting trace - quite possibly we get 'screenParametersChanged' called when windows are minimized / maximised etc.

If OSX is broadcasting that to every app window when we minimize one of them, and then we go on to re-draw the entire window; and then we broadcast this:

    CallCallback( SalEvent::DisplayChanged, nullptr );

to every window as well - we end up with an N^2 re-render of each window =) which seems a little OTT.

Quite possibly:

void AquaSalFrame::screenParametersChanged()
{
    UpdateFrameGeometry();

    if( mpGraphics )
        mpGraphics->updateResolution();
    CallCallback( SalEvent::DisplayChanged, nullptr );
}

should check to see whether the frame geometry actually changed and only emit the event if that is the case.

Having said that 'DisplayChanged' - is really an event that should only get emitted when the physical display and/or monitor size changes - like plugging in a remote display etc.

Have we emitted that in error much more frequently than we should:

osx/salinst.cxx-    [[NSNotificationCenter defaultCenter] addObserver: NSApp
osx/salinst.cxx:                                          selector: @selector(screenParametersChanged:)
osx/salinst.cxx-                                          name: NSApplicationDidChangeScreenParametersNotification
osx/salinst.cxx-                                          object: nil ];

I imagine we don't need to do:

osx/vclnsapp.mm:-(void)screenParametersChanged: (NSNotification*) pNotification
osx/vclnsapp.mm-{
osx/vclnsapp.mm-    (void)pNotification;
osx/vclnsapp.mm-    SolarMutexGuard aGuard;
osx/vclnsapp.mm-
osx/vclnsapp.mm-    SalData* pSalData = GetSalData();
osx/vclnsapp.mm-    std::list< AquaSalFrame* >::iterator it;
osx/vclnsapp.mm-    for( it = pSalData->maFrames.begin(); it != pSalData->maFrames.end(); ++it )
osx/vclnsapp.mm-    {
osx/vclnsapp.mm:        (*it)->screenParametersChanged();
osx/vclnsapp.mm-    }

For every frame - if we are also then going to re-broadcast this to every frame higher up the stack.

Of course. Just based on some quick code-reading, I have no Mac to hack or test this on.

(In reply to Telesto from comment #14)
> In can't help either. By the way I noticed a deprecation:
> 

>    626 	SAL_WNODEPRECATED_DECLARATIONS_PUSH
>    627 	    // 'NSAnyEventMask' is deprecated: first deprecated in macOS
> 10.12


I see this too, but I thought it was unrelated and was in two minds about opening a bug report for it. As the console message that is thrown when this happen talks about "in future versions this will throw an exception", I did wonder whether we weren't setting ourselves up for a future SIGABRT with this.

@Telesto : perhaps you could open a separate bug report for this ?

*** Bug 105068 has been marked as a duplicate of this bug. ***

Created attachment 130356 [details]
LLDB Backtrace, Build Log

New backtrace
Version: 5.4.0.0.alpha0+
Build ID: 88f561204d7cee25633df8117cc8d7e1ebd8e9ad
CPU Threads: 4; OS Version: Mac OS X 10.12.2; UI Render: default; 
Locale: en-US (en_US.UTF-8); Calc: group

Hey there - the good news is, I finally have an old 2nd hand Mac; but of course, still -very- limited time - so, when I get a build hopefully can reproduce & look into some of these issues.

*** Bug 107578 has been marked as a duplicate of this bug. ***

Created attachment 136089 [details]
Xcode instruments screenshots and BT

As requested in comment 9 a Xcode trace and some screenshots

Michael:
the pb seems to be in this part:
  7 libswlo.dylib SwEditWin::DataChanged(DataChangedEvent const&) /Users/demo/lode/dev/core/sw/source/uibase/docvw/edtwin3.cxx:166
  8 libvcllo.dylib vcl::Window::CompatDataChanged(DataChangedEvent const&) /Users/demo/lode/dev/core/vcl/source/window/window.cxx:3709
  9 libvcllo.dylib vcl::Window::NotifyAllChildren(DataChangedEvent&) /Users/demo/lode/dev/core/vcl/source/window/event.cxx:43
  10 libvcllo.dylib vcl::Window::NotifyAllChildren(DataChangedEvent&) /Users/demo/lode/dev/core/vcl/source/window/event.cxx:48

If I interpret this correctly, there's a recursive loop here:
41  void Window::NotifyAllChildren( DataChangedEvent& rDCEvt )
42  {
43      CompatDataChanged( rDCEvt );
44 
45      vcl::Window* pChild = mpWindowImpl->mpFirstChild;
46      while ( pChild )
47      {
48          pChild->NotifyAllChildren( rDCEvt ); <--------- recursive loop
49          pChild = pChild->mpWindowImpl->mpNext;
50      }
51  }

because of this CompatDataChanged is called many times, so fonts are reloaded many times.

I thought about adding a "level" argument to NotifyAllChildren so we could distinguish initial call of NotifyAllChildren with the recursive one.
CompatDataChanged should be called only by initial calls.

It would give:

if nLevel
    CompatDataChanged( rDCEvt );
41  void Window::NotifyAllChildren( DataChangedEvent& rDCEvt, int nLevel /* by default value = 0 */  )
42  {
43      if (nLevel) 
44          CompatDataChanged( rDCEvt );
45      vcl::Window* pChild = mpWindowImpl->mpFirstChild;
46      while ( pChild )
47      {
48          pChild->NotifyAllChildren( rDCEvt, nLevel+1 );
49          pChild = pChild->mpWindowImpl->mpNext;
50      }
51  }
what do you think?

Argh, my suggestion is wrong since recursive loop would be useless.
I thought we may transmit nLevel to CompatDataChanged and so towards all the DataChanged methods or adding a Datachanged method with 2 arguments for some cases?

(In reply to Julien Nabet from comment #27)
> Argh, my suggestion is wrong since recursive loop would be useless.
> I thought we may transmit nLevel to CompatDataChanged and so towards all the
> DataChanged methods or adding a Datachanged method with 2 arguments for some
> cases?

I most likely found the culprit. Things are back to normal after reverting: https://cgit.freedesktop.org/libreoffice/core/commit/?id=0497864bd4f603605997938d504ef9598623e713

(In reply to Telesto from comment #28)
> (In reply to Julien Nabet from comment #27)
>...
> I most likely found the culprit. Things are back to normal after reverting:
> https://cgit.freedesktop.org/libreoffice/core/commit/
> ?id=0497864bd4f603605997938d504ef9598623e713

Good catch!

David: Thought you might be interested in this one. In comment 26, I found a recursive loop which call the indicated function. Any idea how to fix this?

*** Bug 113467 has been marked as a duplicate of this bug. ***

@David : any thoughts on whether we can revert the commit in question or whether it can be changed somehow to avoid the huge penalty it causes on MacOS ?

For what it's worth:
The problem seems to starts with screenParametersChanged which leads to a DisplayChanged event which leads to a DataChangedEventType::DISPLAY event ending up refreshing all fonts (or something like that)

The screenParametersChanged 'broadcast' will happen even when I remove the screenParametersChanged stuff here
https://opengrok.libreoffice.org/xref/core/vcl/osx/salinst.cxx#166
because of https://opengrok.libreoffice.org/xref/core/vcl/osx/salframeview.mm#304

ScreenParametersChanged 'broadcast' will also happen when I comment out https://opengrok.libreoffice.org/xref/core/vcl/osx/salframeview.mm#304
and letting salinst.cxx#166 intact.

I can't seem to reproduce this, with a debugging build of current master on High Sierra, on an iMac, with 20 empty Writer documents. Has the bug gone away in master, or does it not happen in High Sierra, or is my machine so powerful that I don't see it? Or what am I missing?

(I don't really think the last, this machine is not *that* much more powerful than a 2014 MacBook Air, I should see some short amount of unresponsiveness if the problem was there, I think. And anyway, this is a debugging (not optimised) build, so performance problems should be more obvious than with a production build.)

I still reproduce this, using the steps in comment 6
1) Opened 15 blank documents
2) Minimized three of the document windows.


Another way
1. Open System Preferences from the Apple menu and choose “Dock”
2. Check the box for “Automatically hide and show the Dock” by clicking the checkbox next to it
3. Start Libreoffice Writer
4. Create 12-20 blank documents
5. Put your computer to sleep (by choosing Sleep from the Apple menu)
6. Wake Mac again
7. Create a new document (CMD + N)

No repro for me either now with

Version: 6.1.0.0.alpha0+
Build ID: 44e9bbc29cc37d2bac089b8f051478f62f7d5d31
CPU threads: 4; OS: Mac OS X 10.13.2; UI render: default; 
Locale: fr-FR (fr_FR.UTF-8); Calc: group threaded

Debug enabled build

I tested on Macmini 2014, 2,6 GHz Intel Core i5, 8 Go 1600 MHz DDR3, Intel Iris 1536 Mo.

Odd, I still repro it with
Version: 6.1.0.0.alpha0+
Build ID: 6fc9d4a482ab50a1bf8fefb1dae2a6ded3c7e3dd
CPU threads: 4; OS: Mac OS X 10.13.3; UI render: default; 
TinderBox: MacOSX-x86_64@49-TDF, Branch:master, Time: 2018-01-24_04:46:24
Locale: nl-NL (nl_US.UTF-8); Calc: group threaded

with a regular daily build and with my own symbol only build..

*No special settings or applications or fonts
*No external monitor attached
*Java disabled

Argh.. I probably found the cause. The dock size slider in System Preferences -> Dock is set halfway by default. However, the slider range is totally wrong. The dock size only changes between 0-40%. Setting the slider to 50% will cause a mismatch, triggering NSApplication notifications...

*** Bug 103126 has been marked as a duplicate of this bug. ***

(In reply to Telesto from comment #39)
> Argh.. I probably found the cause. The dock size slider in System
> Preferences -> Dock is set halfway by default. However, the slider range is
> totally wrong. The dock size only changes between 0-40%. Setting the slider
> to 50% will cause a mismatch, triggering NSApplication notifications...


Yep. Confirming with

Version: 6.1.0.0.alpha0+
Build ID: 44e9bbc29cc37d2bac089b8f051478f62f7d5d31
CPU threads: 4; OS: Mac OS X 10.13.2; UI render: default; 
Locale: fr-FR (fr_FR.UTF-8); Calc: group threaded

I've managed to freeze LO completely just by opening up 20 new Writer documents and then reducing one window, after setting the Dock to 50% with the slider. I didn't need to send LO to sleep.

I don't see any percentage scale in the System Preferences > Dock > Size slider. When you talk about 50% or 40%, is that just an eyeballed estimation? After touching it, how do I get it back to the default? (Not that it matters much to me how big it is, I practically never use the Dock for anything, and of course I have it to auto-hide.)

(In reply to Tor Lillqvist from comment #42)
> I don't see any percentage scale in the System Preferences > Dock > Size
> slider. When you talk about 50% or 40%, is that just an eyeballed
> estimation? After touching it, how do I get it back to the default? (Not
> that it matters much to me how big it is, I practically never use the Dock
> for anything, and of course I have it to auto-hide.)

Sorry, that's my eyeball estimation :-). Everything is working fine as long as the dock responds to the Dock Size slider. The issue starts when the Dock stops growing, while the slider is suggestion room for a larger one. It's probably set to the middle by default (and that's already to much for my 11" screen)

My experience with Macs is very limited. So it might not be reproducible on no-retina Macs and/or Macs with a smaller screen dimension.

Btw, no clue how the set it back to the default setting. Except for a new user profile, or guessing the middle of the slider.

(In reply to Telesto from comment #44)
> Sorry, that's my eyeball estimation :-). Everything is working fine as long
> as the dock responds to the Dock Size slider. The issue starts when the Dock
> stops growing, while the slider is suggestion room for a larger one. It's
> probably set to the middle by default (and that's already to much for my 11"
> screen)

Dammit, this still isn't the whole story. The issue (also) arises with to many windows minimised to the dock. At the point where the icons are shrinking.. :( 

1) Opened 15 blank documents
2) Minimise them all to the dock
2) Restore a minimised Writer document.

Upping the importance to raise visibility of this bug.

Thanks to all who try to fix this one, it is really a painful one!

One thing that is ~obviously wrong is this:


    frame #38: 0x00000001150cbd8a libvcllo.dylib`SalTimer::CallCallback(this=0x000060000001b630, idle=true) + 58 at saltimer.hxx:55
...
libvcllo.dylib`AquaSalInstance::AnyInput(this=0x00006080000b9aa0, nType=KEYBOARD) + 603 at salinst.cxx:786
    frame #52: 0x0000000114f58ef6 libvcllo.dylib`Application::AnyInput(nType=KEYBOARD) + 38 at svapp.cxx:631

The windows impl of AnyInput doesn't look like it processes timers or events - it is a real 'Peek' method - not expected to re-enter in a weird way:

vcl/win/app/salinst.cxx (WinSalInstance::AnyInput)

packed with this sort of thing:

        if ( PeekMessageW( &aMsg, nullptr, 0, 0, PM_NOREMOVE | PM_NOYIELD ) )

vs.

vcl/osx/salinst.cxx (AquaSalInstance::AnyInput)

which does:

    NSEvent* pEvent = [NSApp nextEventMatchingMask: nEventMask untilDate: nil
                            inMode: NSDefaultRunLoopMode dequeue: NO];

Which looks like a go-wild "run the loop" crazy thing ;-) which may be a wider systemic problem highlighted here (?)

Are we adding timers to the wrong mode for that loop ? or do we need a custom mode so we can exclude ~everything from running and just peek ? or perhaps a different method call ?

In fact, the documentation for the Win32 PeekMessage() https://msdn.microsoft.com/en-us/library/windows/desktop/ms644943(v=vs.85).aspx does describe that it is not as trivial as one might hope. "During this call, the system delivers pending, nonqueued messages, that is, messages sent to windows owned by the calling thread using the SendMessage, SendMessageCallback, SendMessageTimeout, or SendNotifyMessage function. Then the first queued message that matches the specified filter is retrieved. The system may also process internal events."

And about SendMessage(), "The SendMessage function calls the window procedure for the specified window and does not return until the window procedure has processed the message".

Ah yes, now I think I can reproduce it.

Hokay - so, lets compare it with the gtk3 backend which we know works; that pulls events from the gdk event queue - and stuffs them back without processing any =)

It also first calls gdk_events_pending() - which does the underlying socket I/O to the X server (when using X) - via 'XPending()' -> XEventsQueued with QueuedAfterFlush - but I don't see any event processing; particularly of the glib mainloop which handles timeouts =)

Hence the "I don't expect that" really =)

I wonder if a good fix would be to modify AquaSalFrame::screenParametersChanged() so that if nothing actually has changed (but we got the NSApplicationDidChangeScreenParametersNotification notification because of something unessential like the Dock size changing), then don't call CallCallback(SalEvent::DisplayChanged, nullptr).

Here is a sample stack trace from Xcode while it is doing something for very long... Horror, horror.

#0	0x000000010a9ca9b2 in CommonSalLayout::CommonSalLayout(CoreTextStyle const&) at /Users/tml/lo/osx/vcl/source/gdi/CommonSalLayout.cxx:243
#1	0x000000010a9caedd in CommonSalLayout::CommonSalLayout(CoreTextStyle const&) at /Users/tml/lo/osx/vcl/source/gdi/CommonSalLayout.cxx:243
#2	0x000000010abeafa0 in AquaSalGraphics::GetTextLayout(ImplLayoutArgs&, int) at /Users/tml/lo/osx/vcl/quartz/salgdi.cxx:518
#3	0x000000010a632f3b in OutputDevice::ImplLayout(rtl::OUString const&, int, int, Point const&, long, long const*, SalLayoutFlags, vcl::TextLayoutCache const*) const at /Users/tml/lo/osx/vcl/source/outdev/text.cxx:1335
#4	0x000000010a634cb6 in OutputDevice::GetTextArray(rtl::OUString const&, long*, int, int, vcl::TextLayoutCache const*, SalLayout const*) const at /Users/tml/lo/osx/vcl/source/outdev/text.cxx:992
#5	0x000000010a634a76 in OutputDevice::GetTextWidth(rtl::OUString const&, int, int, vcl::TextLayoutCache const*, SalLayout const*) const at /Users/tml/lo/osx/vcl/source/outdev/text.cxx:912
#6	0x000000010a521f7b in ImplListBoxWindow::ImplUpdateEntryMetrics(ImplEntryType&) at /Users/tml/lo/osx/vcl/source/control/imp_listbox.cxx:640
#7	0x000000010a5211d6 in ImplListBoxWindow::ImplCalcMetrics() at /Users/tml/lo/osx/vcl/source/control/imp_listbox.cxx:556
#8	0x000000010a522685 in ImplListBoxWindow::SetUserItemSize(Size const&) at /Users/tml/lo/osx/vcl/source/control/imp_listbox.cxx:590
#9	0x000000010a4be236 in ComboBox::SetUserItemSize(Size const&) at /Users/tml/lo/osx/vcl/source/control/combobox.cxx:1256
#10	0x0000000109072f68 in FontNameBox::ImplCalcUserItemSize() at /Users/tml/lo/osx/svtools/source/control/ctrlbox.cxx:826
#11	0x0000000109071ed1 in FontNameBox::Fill(FontList const*) at /Users/tml/lo/osx/svtools/source/control/ctrlbox.cxx:800
#12	0x0000000107c01ac7 in SvxFontNameBox_Impl::Fill(FontList const*) at /Users/tml/lo/osx/svx/source/tbxctrls/tbcontrl.cxx:227
#13	0x0000000107bdee68 in lcl_GetDocFontList(FontList const**, SvxFontNameBox_Impl*) at /Users/tml/lo/osx/svx/source/tbxctrls/tbcontrl.cxx:958
#14	0x0000000107bdf89e in SvxFontNameBox_Impl::DataChanged(DataChangedEvent const&) at /Users/tml/lo/osx/svx/source/tbxctrls/tbcontrl.cxx:1120
#15	0x00000001820d72b0 in framework::ToolBarManager::DataChanged(DataChangedEvent const*) at /Users/tml/lo/osx/framework/source/uielement/toolbarmanager.cxx:1823
#16	0x00000001820c0448 in framework::ToolBarManager::LinkStubDataChanged(void*, DataChangedEvent const*) at /Users/tml/lo/osx/framework/source/uielement/toolbarmanager.cxx:1807
#17	0x000000010a41cca8 in Link<DataChangedEvent const*, void>::Call(DataChangedEvent const*) const at /Users/tml/lo/osx/include/tools/link.hxx:84
#18	0x000000010a41cc40 in ToolBox::DataChanged(DataChangedEvent const&) at /Users/tml/lo/osx/vcl/source/window/toolbox.cxx:4081
#19	0x000000010a460322 in vcl::Window::CompatDataChanged(DataChangedEvent const&) at /Users/tml/lo/osx/vcl/source/window/window.cxx:3801
#20	0x000000010a2df29f in vcl::Window::NotifyAllChildren(DataChangedEvent&) at /Users/tml/lo/osx/vcl/source/window/event.cxx:43
#21	0x000000010a2df2ec in vcl::Window::NotifyAllChildren(DataChangedEvent&) at /Users/tml/lo/osx/vcl/source/window/event.cxx:48
#22	0x000000010a2df2ec in vcl::Window::NotifyAllChildren(DataChangedEvent&) at /Users/tml/lo/osx/vcl/source/window/event.cxx:48
#23	0x000000010a2df2ec in vcl::Window::NotifyAllChildren(DataChangedEvent&) at /Users/tml/lo/osx/vcl/source/window/event.cxx:48
#24	0x000000010aa94443 in Application::NotifyAllWindows(DataChangedEvent&) at /Users/tml/lo/osx/vcl/source/app/svapp.cxx:762
#25	0x000000010a47cede in ImplHandleSalSettings(SalEvent) at /Users/tml/lo/osx/vcl/source/window/winproc.cxx:2128
#26	0x000000010a479be8 in ImplWindowFrameProc(vcl::Window*, SalEvent, void const*) at /Users/tml/lo/osx/vcl/source/window/winproc.cxx:2474
#27	0x000000010abfab55 in SalFrame::CallCallback(SalEvent, void const*) const at /Users/tml/lo/osx/vcl/inc/salframe.hxx:279
#28	0x000000010ac86c2f in AquaSalFrame::screenParametersChanged() at /Users/tml/lo/osx/vcl/osx/salframe.cxx:271
#29	0x000000010ad5b42d in ::-[VCL_NSApplication screenParametersChanged:](NSNotification *) at /Users/tml/lo/osx/vcl/osx/vclnsapp.mm:367

Nice trace - so; I imagine that DisplayChanged is presumably the right thing to emit only when something changed - eg. the space available for the app (does that happen when the dock re-sizes ?

Also - I'm suspicious of:

svx/source/tbxctrls/tbcontrl.cxx-    else if ( ( rDCEvt.GetType() == DataChangedEventType::FONTS ) ||
svx/source/tbxctrls/tbcontrl.cxx:              ( rDCEvt.GetType() == DataChangedEventType::DISPLAY ) )

I guess this is perhaps to handle things like font-hint changes on Linux (perhaps) - and I imagine that this particular font combo box is -very- expensive to setup & re-render.

Might be nice to just use FONTS for that - and try to detect if any display settings affect font rendering - and emit a FONTS changed if they do (?) =)

The:
            // HACK: Comparing is incomplete

comment in lcl_GetDocFontList looks particularly interesting to investigate I guess =) if we can avoid re-building it I imagine life is far better.

Suggested fix at https://gerrit.libreoffice.org/50249

FYI, here is some timing debugging output from when just one Writer document was open and I changed the Dock size:

> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.000006 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.027414 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.027461 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.023375 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.023460 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.023808 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.023851 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.021801 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.021874 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.008783 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.008825 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.010233 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.010275 s
> debug:90663:6971042: -[VCL_NSApplication screenParametersChanged]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.022160 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.010850 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.023778 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.021911 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.024892 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.021507 s
> debug:90663:6971042: -[VCL_NSApplication screenParametersChanged] took 0.125439 s

and here with three documents open:

> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.000007 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.074095 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.074144 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.069474 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.069551 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.068246 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.068291 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.066944 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.066994 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.024242 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.024287 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.067261 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.067301 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.066743 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.066820 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.023351 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.023382 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.025091 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.025230 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.026617 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.026713 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.067003 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.067048 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.067794 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.067872 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.068892 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.068934 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.069128 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.069176 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.068469 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.068525 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.024791 s
> debug:90663:6971042: -[SalFrameWindow windowDidChangeScreen] took 0.024842 s
> debug:90663:6971042: -[VCL_NSApplication screenParametersChanged]
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.068519 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.068946 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.068762 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.067797 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.066688 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.067541 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.067825 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.024071 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.069154 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.068377 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.068981 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.025192 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.068966 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.068955 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.069286 s
> debug:90663:6971042:   AquaSalFrame::screenParametersChanged: CallCallback took 0.068227 s
> debug:90663:6971042: -[VCL_NSApplication screenParametersChanged] took 1.008116 s

Tor Lillqvist committed a patch related to this issue.
It has been pushed to "master":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=715b7b6f346fdd9c856db268dcd66334b58c273c

tdf#103571: Avoid spurious heavy SalEvent::DisplayChanged callbacks

It will be available in 6.1.0.

The patch should be included in the daily builds available at
http://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
http://wiki.documentfoundation.org/Testing_Daily_Builds

Affected users are encouraged to test the fix and report feedback.

Patch looks good - although some comments in the gerrit back-port =)

I'd really like us to fix the cross-platform issue that this shows up though:

svx/source/tbxctrls/tbcontrl.cxx 's:
            // HACK: Comparing is incomplete

Code seems bad to me - spending all this time doing ~nothing when we plug a remote display in (and on every platform) also seems like a really poor use of time =)

I'd like to investigate why this FontList comparison says the font list has changed when this event occurs - triggering the expensive re-build of the font-list - when it has not =)

Perhaps more interestingly - if that work is done at startup - before we create a new top-level frame ;-) [ as it may well be ] can we do something to speed up new window creation here by eg. deferring that work: just dirtying the combo-box, or having a single item in it which is the current font, and populating it only on first-click ? =) or somesuch clever.

Would be good to get a faster experience on all platforms from this if possible =)

Would also be good to test changing the LCD font rendering settings [ if indeed such settings exist ;-] on Linux which -should- cause the UI to completely refresh - including these fonts: almost certainly it's not an issue because the actual rendering (vs. measuring etc. in that list) should occur at a very low level; but worth a check.

Thanks Tor ! =)

Could this patch make it into 6.0.1? Please?

Sorry, meant 6.0.2 (6.0.2.1 was already built two days ago).

Would be great if you who have been able to reproduce the problem (using any approach) could check whether it is fixed now in master. At least the way I could reproduce this is definitely fixed.

Tor Lillqvist committed a patch related to this issue.
It has been pushed to "libreoffice-6-0":

http://cgit.freedesktop.org/libreoffice/core/commit/?id=f99b91ab0a67ce23f1c11bdb67370c0773813d15&h=libreoffice-6-0

tdf#103571: Avoid spurious heavy SalEvent::DisplayChanged callbacks

It will be available in 6.0.2.

The patch should be included in the daily builds available at
http://dev-builds.libreoffice.org/daily/ in the next 24-48 hours. More
information about daily builds can be found at:
http://wiki.documentfoundation.org/Testing_Daily_Builds

Affected users are encouraged to test the fix and report feedback.

Great, waiting for any new daily or pre-release builds available for macOS, will report back.

Setting to NEEDINFO, awaiting confirmation that problem is fixed.

No repro for me anymore with my own master build of 01/03 or 02/03 (not sure)

Version: 6.1.0.0.alpha0+
Build ID: 9122f4598450d8a96e63fb29cc8166a6ae09587a
CPU threads: 4; OS: Mac OS X 10.13.3; UI render: default; 
Locale: fr-FR (fr_FR.UTF-8); Calc: group

The target should be 6.0.3. It didn't make it into 6.0.2