Aron could you take a look at this one.

Found in
Version: 5.4.0.0.alpha0+
Build ID: b41186a2fc49e440890b8c86e5367352ffaf9cd6
CPU Threads: 4; OS Version: Windows 6.19; UI Render: GL; 
TinderBox: Win-x86@42, Branch:master, Time: 2017-01-26_01:50:40
Locale: nl-NL (nl_NL); Calc: CL

and in
Version: 5.1.0.3
Build ID: 5e3e00a007d9b3b6efb6797a8b8e57b51ab1f737
CPU Threads: 4; OS Version: Windows 6.2; UI Render: default; 
Locale: en-US (nl_NL)

but not in
Version: 5.0.6.3
Build ID: 490fc03b25318460cfc54456516ea2519c11d1aa
Locale: en-US (nl_NL)

I cannot compare with 5.0.2.2, because it says "too many or too few spaces next to parentheses". It works fine in 5.4.

Retested it again. Still slow compared to Lib 5.0.2.2
Version: 5.4.0.0.alpha0+
Build ID: 2670ca3fc597decae78499d1397539668eb84e5e
CPU Threads: 4; OS Version: Windows 6.19; UI Render: default; 
TinderBox: Win-x86@42, Branch:master, Time: 2017-01-31_05:32:46
Locale: nl-NL (nl_NL); Calc: CL

Fix for "too many or too few spaces next to parentheses":
1. Start LibreOffice
2. Go to Options -> Language Settings -> Set Local Settings to "English (USA)" 
3. Restart LibreOffice

Ok in 5.0.2.2 it is super fast!

Version: 5.0.2.2 (x64)
Build ID: 37b43f919e4de5eeaca9b9755ed688758a8251fe
Locale: en-US (fi_FI)

Originally takes about 30s on my computer, after these commits it's about 2-2.5x more (60-75s). While the amount of delay could be up for discussion, probably something around the original runtime would be more desirable.
Ash, Laszlo, Miklos? Does this require a change in the scheduler, or in the Logo interpreter?

https://cgit.freedesktop.org/libreoffice/core/commit/?id=3dfeae78cac187ec27f873271005c77aebafd038
author		Miklos Vajna <vmiklos@collabora.co.uk>	2015-09-09 10:30:18 (GMT)
committer	Miklos Vajna <vmiklos@collabora.co.uk>	2015-09-09 10:30:57 (GMT)

"vcl: restore lost hunk in Scheduler::ImplStartTimer()
Regression from commit 6d64d2f38d9f6c2f54e05675ecd0709eabf6d8ca (Minor refactoring and cleanup of Scheduler and Timer., 2015-07-19), the old Timer::ImplStartTimer() used to set nMS to at least 1, but the new Scheduler::ImplStartTimer() didn't do that."

https://cgit.freedesktop.org/libreoffice/core/commit/?id=6d64d2f38d9f6c2f54e05675ecd0709eabf6d8ca
author		Ashod Nakashian <ashodnakashian@yahoo.com>	2015-07-19 23:40:18 (GMT)
committer	Michael Meeks <michael.meeks@collabora.com>	2015-09-04 18:43:41 (GMT)

"Minor refactoring and cleanup of Scheduler and Timer."

@Jan-Marek: Might it be related to the scheduler?

All my Scheduler changes are just in master AKA 6.0. Those 1ms delays, reintroduced by Miklos to fix the workaround for AutoTimers rescheduling instantly again, don't exists anymore. So on master it's probably fixed (but for sure you have other bugs).

Repro with
Version: 6.2.0.0.alpha0+
Build ID: 1b21ff86effe58ae368457de8fec654ba4c8edd9
CPU threads: 4; OS: Windows 6.3; UI render: default; 
TinderBox: Win-x86@42, Branch:master, Time: 2018-07-30_03:13:35
Locale: en-US (nl_NL); Calc: CL

still slow
Version: 7.3.0.0.alpha0+ (x64) / LibreOffice Community
Build ID: 2a151d1d5bc055d5e0011460b6ec42ea9f34f880
CPU threads: 4; OS: Windows 6.3 Build 9600; UI render: Skia/Raster; VCL: win
Locale: en-US (nl_NL); UI: en-US
Calc: CL

So this should have been just a quick look and turned into some hours analysis with multiple problems unveiled...

Just for the "fun" of it, I did throw the example into callgrind. In my symbol+assert build, I found that the primary problem is dynamic_cast's strcmp from the assert in "SwContact* GetUserCall(const SdrObject* pObj)". Commenting that, and running callgrind again, I found dynamic_cast still to be a problem, but much less ;-) Now 10% of the time is spend in __gnu_cxx::__normal_iterator...

SwObjectFormatter::FormatObjsAtFrame_
SwSortedObjs::ListPosOf
__gnu_cxx::__normal_iterator

That's one reason why the progress gets slower. The LO code iterates over the graphics objects vector to find the matching SwAnchoredObject. Normally that code is no problem, since we don't have 400 draw objects and "everytime" add a new one causing a relayout with several of these lookup.

And the display was never refreshed in callrind, until LibreLogo was finished.

But back to the original problem:

!! 1. Make sure the document language is English !!

I had my master build with en UI, but German system, resulting in an error message about braces and whitespace. I originally didn't even realize the error message was German; took me, while trying to fix the logo program ;-)

master kf5 (symbols + asserts, no debug): ~40s
5.0.6.2 gtk2 (from git releases; I like that repo): ~120s to finish with several "hiccups", i.e. the turtle speed differed (different from the general slowdown already described above)
master gtk3: ~150s
master gen: ~4s (really; just does a single paint refresh, and I guess no intermediate layouts; not yet analyzed...)

FWIW the "svx::SdrPaintView aComeBackIdle" has TaskPriority::REPAINT, but it probably should be TaskPriority::RESIZE AKA just above repaint (and maybe RESIZE should be rename PREPAINT, and REPAINT just PAINT...). It feels a bit faster, but with kf5 at 40s + manual timing...

There are two main difference between Qt and the other system loops:
1. Qt can't process single events. You can just decide between "process all events" and "wait for events and then process all". And it has a bit different painting semantics, so a refresh most times get queued in the system event loop. I'm for that approach generally...
2. gtk and win process LO events via system loop. All other process them always before system events. That is nothing new, but it might interfere here and they should probably get converted to the general processing via SalUserEventList (don't ask me why it's called UserEvent...; I just introduced SalUserEventList, not SalUserEvent).

This needs much more work; maybe we should just switch to GMainLoop, but that would be a mayor change for all backends again...) and we have the UI in main problem, bust that might be solvable generally with std::

And then there is the headless locking problem with UI tests too, where we don't want to run the main loop via yield "out of order", with non-releasing SolarMutex m_bNoYieldLock hack.

And nothing obvious and quick to fix this. I guess at least a month to convert all VCL backends after finishing headless (which should work; it has some focus handling problem, which are hacked around by ignoring visibility...).

std:: should have been std::function<void()>.

(In reply to Jan-Marek Glogowski from comment #13)
> So this should have been just a quick look and turned into some hours
> analysis with multiple problems unveiled...

Thanks for the 'quick' look (and insights). Me wondering how often logo being truly c.q. how much engineering time should be spent on this. It's kind of a trivial feature to me (personal opinion).

Or is there some overall benefit, bigger compared to logo (like harmonizing system loops cross platform)

Not saying that economics theory being the only perspective.. The challenge or fun might maybe a reason for looking into this..

(In reply to Telesto from comment #15)
> (In reply to Jan-Marek Glogowski from comment #13)
> > So this should have been just a quick look and turned into some hours
> > analysis with multiple problems unveiled...
> 
> Thanks for the 'quick' look (and insights). Me wondering how often logo
> being truly c.q. how much engineering time should be spent on this. It's
> kind of a trivial feature to me (personal opinion).
> 
> Or is there some overall benefit, bigger compared to logo (like harmonizing
> system loops cross platform)

There is no real problem with LibreLogo AFAIK, except that it's kind of a non-feature which even caused security problems due its Python implementation (I have no idea how someone thought this might be a sensible feature for LO...). But this is a good and easy test, which is hard to find for the whole system event loop integration, let alone unit tests.

The event loop will always be very system specific. But the LO scheduler and the processing of LO internal events (AKA UserEvent) is definitely a good idea to further unify (OTOH every time I touched this low level stuff, I broke things, so I'm not really eager; nobody else even wants to touch it). 

> Not saying that economics theory being the only perspective.. The challenge
> or fun might maybe a reason for looking into this..

I failed to parse this. This is nothing I will / can do in my free time, if that's what "economics" refer to. The city of Munich "sponsored" a lot of this, so even if it didn't directly help any particular of their problem, I could work on it to tackle some underlying problems instead of somehow working around them. It also didn't help, that the VCL plugins did stuff completely or slightly different without any explanation... "Why?" is the most common thought when reading LO code (next to wtf, obviously), not what; at least for me.

(In reply to Jan-Marek Glogowski from comment #16)
> The event loop will always be very system specific. But the LO scheduler and
> the processing of LO internal events (AKA UserEvent) is definitely a good
> idea to further unify (OTOH every time I touched this low level stuff, I
> broke things, so I'm not really eager; nobody else even wants to touch it). 

No surprise, here ;-). It's good enough, is perfectly fine 


> > Not saying that economics theory being the only perspective.. The challenge
> > or fun might maybe a reason for looking into this..
> 
> I failed to parse this. 

Well in economics all is about distributing resources most efficiently. However LibreOffice is also promoted as 'fun-project for developers'. Defeating market logic (economics). So someone might jump into it out of curiosity/challenge [in some utopia ...] and spend weeks on this unpaid.. [sarcasm] 

>This is nothing I will / can do in my free time, if
> that's what "economics" refer to. The city of Munich "sponsored" a lot of
> this, so even if it didn't directly help any particular of their problem, I
> could work on it to tackle some underlying problems instead of somehow
> working around them.

Is Munich still 'sponsoring' development? They are moving back to MSO, right?

> It also didn't help, that the VCL plugins did stuff
> completely or slightly different without any explanation... "Why?" is the
> most common thought when reading LO code (next to wtf, obviously), not what;
> at least for me.

Code is to me a kind of abracadabra (and coding a black art). Assessing code quality is kind out of scope for me. Aware of lots of bug tracker references pointing to nowhere these days.. 

Anyhow, I was more or less surprised by the analysis at comment 13 (interesting to read though).

---
Changing priority ..

(In reply to Jan-Marek Glogowski from comment #13)
> So this should have been just a quick look and turned into some hours
> analysis with multiple problems unveiled...
> 
> Just for the "fun" of it, I did throw the example into callgrind. In my
> symbol+assert build, I found that the primary problem is dynamic_cast's
> strcmp from the assert in "SwContact* GetUserCall(const SdrObject* pObj)".
> Commenting that, and running callgrind again, I found dynamic_cast still to
> be a problem, but much less ;-) Now 10% of the time is spend in
> __gnu_cxx::__normal_iterator...
> 
> SwObjectFormatter::FormatObjsAtFrame_
> SwSortedObjs::ListPosOf
> __gnu_cxx::__normal_iterator
> 
> That's one reason why the progress gets slower. The LO code iterates over
> the graphics objects vector to find the matching SwAnchoredObject. Normally
> that code is no problem, since we don't have 400 draw objects and
> "everytime" add a new one causing a relayout with several of these lookup.
> 
> And the display was never refreshed in callrind, until LibreLogo was
> finished.
> 

@Noel, I thought you might be interested in this comment from Jan-marek

Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/e463cc0c8e2582e2cb57ab64a74a6a5cdd9b9787

less OUString construction on hot path (tdf#105575)

It will be available in 7.3.0.

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

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

So I have done what I can, but fundamentally what is happening is that the python code that interprets Logo is triggering the rendering too often, and then it ends up fighting to get access to the SolarMutex, because the main thread is too busy rendering, and keeps the SolarMutex locked while doing so.

I think the python code can be made a lot faster by things like

(*) keeping track of the position locally, instead of calling setPosition all the time.
(*) possibly using XMultiPropertySet interface to set multiple properties in one call.
(*) possibly using lockController()/unlockController() while manipulating the shape, to prevent a render/repaint from kicking in until it is done with the current shape manipulation.

But that is someone else's problem, I don't feel like playing with that code.

Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/fa01f5a1feeb93a88a330daeec8177a39916e6a3

tdf#105575 Slow rendering when using a Logo command

It will be available in 7.3.0.

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

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

Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/d29eb3d715a2bfd37c37e098d4f1c4600332487d

no need to lookup window if cursor has not moved (tdf#105575)

It will be available in 7.3.0.

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

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

Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/58b2d04ddab5a678921610bf9e9a5a95ae660a17

do less copying when constructing 2d sequence (tdf#105575)

It will be available in 7.3.0.

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

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

Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/889df64fbb9534491b76140d63b4340091c763e4

reduce alloc costs for some basegfx objects (tdf#105575)

It will be available in 7.3.0.

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

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

Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/f29ef71073bb31f05d6cc50f952e827134868c2d

avoid constructing OUString on hot path (tdf#105575)

It will be available in 7.3.0.

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

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

All: many thanks for the bug report and your comments and help!

Jan-Marek, Noel: many thanks for the detailed analysis and for the performance fixes. I'm going to check/add the suggested improvements at the pyUNO/Logo side.

Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/2e74c1107bc8422ee7a819722f3f0a366127330f

use visitor callback to avoid container construction (tdf#105575)

It will be available in 7.3.0.

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

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

Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/60485d591882954bbec717bfc0f4ffce8c9e9d5e

reduce skia re-alloc costs (tdf#105575)

It will be available in 7.3.0.

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

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

Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/720e4258ab5f00287098ff945a184bfb43911841

use Primitive2DDecompositionVisitor in ViewObjectContact (tdf#105575)

It will be available in 7.3.0.

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

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

Noel Grandin committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/48c2f0b4b157e133605c99549893521775ede4da

cache access in ConfigurationWrapper (tdf#105575)

It will be available in 7.3.0.

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

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

László Németh committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/e50f0f7342c5618196507771e5f4eb79147477b9

tdf#105575 LibreLogo: speed up by lock (re)paint

It will be available in 7.5.0.

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

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

László Németh committed a patch related to this issue.
It has been pushed to "master":

https://git.libreoffice.org/core/commit/81ce66ab5d77b0171245e05ed609f2305ce89600

tdf#105575 LibreLogo: hide turtle during locking

It will be available in 7.5.0.

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

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

Commit description: 

tdf#105575 LibreLogo: speed up by lock (re)paint

Speed up program execution by default partial
locking of repaint and custom locking of paint,
using UNO lockControllers().

– Default: speed up LABEL and TEXT by locking their repaint
  during the various text operations, i.e. setting size and
  text portion formatting changes were visible, and slow.
  Locking while manipulating a shape was suggested by Noel Grandin.

– Custom: SLEEP command with negative argument calls lockControllers(),
  SLEEP command with not negative argument (and program termination)
  call unlockControllers(), so it's possible to lock program parts to
  speed up program execution e.g. 3-4 times or more. For example:

  ; lock paint until program termination
  SLEEP -1
  program

  or

  ; lock until SLEEP 0
  SLEEP -1
  commands_without_paint
  SLEEP 0 ; unlock a single level and paint/repaint everything

– Add __get_time__() command to get the elapsed time from
  program start for profiling.

Add unit tests.

Note: custom locking with SLEEP has known problems: not connected
lines, bad position of arc/pie, non-working CLEARSCREEN.

Note: The reported code is more than 32 times faster (4 sec vs 2.2 min)
with custom locking, also using the commented line to show not only
the result with 400 circle shapes, but the partial result with 100,
200 and 300 shapes, too:

SLEEP -1
REPEAT 400 [ CIRCLE 10 + REPCOUNT/10 FORWARD 5 + REPCOUNT/10 LEFT 10 ]
; IF REPCOUNT % 100 == 0 [ SLEEP 0 SLEEP -1 ] ; to show partial result
SLEEP 0
PRINT __get_time__()

Commit description (2):

tdf#105575 LibreLogo: hide turtle during locking

It seems painting of the selection around
the turtle is not locked completely, so
hide the turtle to lock that, too, for 20%
or more speed up.

Note: the turtle is still visible, because it is
hidden after locking (until unlocking), but there
is no nore jiggering selection around it.

Jan-Marek, Noel, Telesto, Xisco, Áron and Buvjaga: many thanks for your detailed analysis, fixes, suggestions and QA! I will fix the known issues of the new custom locking, and after that, I plan to add some latency to the repaint, if it's possible.

Note: Also I've already tested the locking of the line and circle/rectangle shape properties, but  it seemed, that is not relevant. I'll check it again with the alpha release, and add to the code, if needed.