Performance issue with official Dark Theme

vdubus commented 7 years ago

I have installed the latest version of Spring Tool Suite, and when using the Dark Theme, it give me a serious performance issue when ANSI Console is also enable (freezing, tacking a lot of time to scroll on the console, etc.)... Yet, I don't have any issue with the default theme.

I am suspecting some kind of conflict between them.

paulvi commented 7 years ago

Have you raised also for Dark Theme (I am not sure what exact you use)? Please raise and link from here.

mihnita commented 7 years ago

I have tried the "plain" Eclipse with both dark and light themes, I don't see any difference. In fact, I use the dark in my day to day work, on Mac, Linux and Windows.

Do you happen to have any extra info? OS + version? Java (Oracle / Open JDK), version, 32/64 bit? Anything else that might help me reproduce this bug? I assume that when you compare the performance that is done with the same output...

vdubus commented 7 years ago

I didn't rise any bug on Eclipse side for the Dark Theme. I am just using the base Dark Theme from eclipse without any modification.

As for my computer configuration:

Windows 7 SP1 64 bits
Oracle JdK 1.8.0_121 64 Bits

mihnita commented 7 years ago

Thank you for the info... Funny, my Windows environment is 100% the same :-)

I don't think this is an Eclipse problem, but I don't think it is my plugin problem either, since this is exactly what I have (also with the standard "Dark Theme", unmodified) I am running Eclipse neon.2, but I did run all versions for the last 2-3 years. And on Linux I am running Eclipse Oxigen (the next version).

I am starting to suspect something with the "Spring Tool Suite", which I have never used. And looks like I will have to install it...

vdubus commented 7 years ago

If you have something you want to check, I could try to help you. Just tell me how I can help.

rodrigoEclipsa commented 6 years ago

pleace uncheck ANSI console output and try again

youngm commented 5 years ago

Happens for me too. I'm using STS 4.

Enable Dark Theme
I Generate some log messages (couple hundred lines??) with ansi colors
Double click "Console" to maximize and see everything drag for a while.
Disable Dark Theme
Run Same test
Everything works great.

No idea if it is a problem with dark theme or ansi color. Just thought I'd add my 2 cents that I see the same problem.

youngm commented 5 years ago

Grabbing a thread dump while things are slow finds this trace which doesn't include STS or ansi console:

"main" #1 prio=6 os_prio=0 tid=0x00000000030c0800 nid=0x5764 runnable [0x0000000000cfa000]
   java.lang.Thread.State: RUNNABLE
        at org.eclipse.swt.internal.win32.OS.ScriptShape(Native Method)
        at org.eclipse.swt.graphics.TextLayout.shape(TextLayout.java:3381)
        at org.eclipse.swt.graphics.TextLayout.shape(TextLayout.java:3561)
        at org.eclipse.swt.graphics.TextLayout.computeRuns(TextLayout.java:250)
        at org.eclipse.swt.graphics.TextLayout.getLineCount(TextLayout.java:1899)
        at org.eclipse.swt.custom.StyledTextRenderer.getTextLayout(StyledTextRenderer.java:1189)
        at org.eclipse.swt.custom.StyledTextRenderer.getTextLayout(StyledTextRenderer.java:871)
        at org.eclipse.swt.custom.StyledTextRenderer.calculate(StyledTextRenderer.java:292)
        at org.eclipse.swt.custom.StyledTextRenderer.calculateClientArea(StyledTextRenderer.java:321)
        at org.eclipse.swt.custom.StyledText.resetCache(StyledText.java:8029)
        at org.eclipse.swt.custom.StyledText.redraw(StyledText.java:7574)
        at org.eclipse.e4.ui.internal.css.swt.dom.scrollbar.StyledTextThemedScrollBarAdapter$StyledTextPaintListener.redrawScrollBars(StyledTextThemedScrollBarAdapter.java:650)
        at org.eclipse.e4.ui.internal.css.swt.dom.scrollbar.AbstractThemedScrollBarAdapter.setScrollBarWidth(AbstractThemedScrollBarAdapter.java:476)
        at org.eclipse.e4.ui.css.swt.dom.StyledTextElement.setScrollBarWidth(StyledTextElement.java:55)
        at org.eclipse.e4.ui.css.swt.properties.custom.CSSPropertyStyledTextScrollbarSWTHandler.applyCSSProperty(CSSPropertyStyledTextScrollbarSWTHandler.java:62)
        at org.eclipse.e4.ui.css.core.impl.engine.AbstractCSSEngine.applyCSSProperty(AbstractCSSEngine.java:732)
        at org.eclipse.e4.ui.css.core.impl.engine.AbstractCSSEngine.applyStyleDeclaration(AbstractCSSEngine.java:542)
        at org.eclipse.e4.ui.css.core.impl.engine.AbstractCSSEngine.applyStyles(AbstractCSSEngine.java:417)
        at org.eclipse.e4.ui.css.core.impl.engine.AbstractCSSEngine.applyStyles(AbstractCSSEngine.java:364)
        at org.eclipse.e4.ui.css.core.impl.engine.AbstractCSSEngine.applyStyles(AbstractCSSEngine.java:435)
        at org.eclipse.e4.ui.css.core.impl.engine.AbstractCSSEngine.applyStyles(AbstractCSSEngine.java:364)
        at org.eclipse.e4.ui.css.core.impl.engine.AbstractCSSEngine.applyStyles(AbstractCSSEngine.java:435)
        at org.eclipse.e4.ui.css.core.impl.engine.AbstractCSSEngine.applyStyles(AbstractCSSEngine.java:364)
        at org.eclipse.e4.ui.css.core.impl.engine.AbstractCSSEngine.applyStyles(AbstractCSSEngine.java:435)
        at org.eclipse.e4.ui.css.core.impl.engine.AbstractCSSEngine.applyStyles(AbstractCSSEngine.java:364)
        at org.eclipse.e4.ui.css.core.impl.engine.AbstractCSSEngine.applyStyles(AbstractCSSEngine.java:435)
        at org.eclipse.e4.ui.css.core.impl.engine.AbstractCSSEngine.applyStyles(AbstractCSSEngine.java:364)
        at org.eclipse.e4.ui.css.core.impl.engine.AbstractCSSEngine.applyStyles(AbstractCSSEngine.java:435)
        at org.eclipse.e4.ui.css.core.impl.engine.AbstractCSSEngine.applyStyles(AbstractCSSEngine.java:364)
        at org.eclipse.e4.ui.css.swt.internal.theme.ThemeEngine.applyStyles(ThemeEngine.java:538)
        at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine$7.setClassnameAndId(PartRenderingEngine.java:1345)
        at org.eclipse.e4.ui.workbench.renderers.swt.SWTPartRenderer.setCSSInfo(SWTPartRenderer.java:114)
        at org.eclipse.e4.ui.workbench.renderers.swt.SWTPartRenderer.styleElement(SWTPartRenderer.java:84)
        at org.eclipse.e4.ui.workbench.renderers.swt.StackRenderer.subscribeTopicActivateChanged(StackRenderer.java:536)
        at sun.reflect.GeneratedMethodAccessor71.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.eclipse.e4.core.internal.di.MethodRequestor.execute(MethodRequestor.java:58)
        at org.eclipse.e4.ui.internal.di.UIEventObjectSupplier$UIEventHandler$1.run(UIEventObjectSupplier.java:67)
        at org.eclipse.swt.widgets.Synchronizer.syncExec(Synchronizer.java:236)
        at org.eclipse.ui.internal.UISynchronizer.syncExec(UISynchronizer.java:147)
        at org.eclipse.swt.widgets.Display.syncExec(Display.java:4594)
        at org.eclipse.e4.ui.internal.workbench.swt.E4Application$1.syncExec(E4Application.java:215)
        at org.eclipse.e4.ui.internal.di.UIEventObjectSupplier$UIEventHandler.handleEvent(UIEventObjectSupplier.java:64)
        at org.eclipse.equinox.internal.event.EventHandlerWrapper.handleEvent(EventHandlerWrapper.java:204)
        at org.eclipse.equinox.internal.event.EventHandlerTracker.dispatchEvent(EventHandlerTracker.java:199)
        at org.eclipse.equinox.internal.event.EventHandlerTracker.dispatchEvent(EventHandlerTracker.java:1)
        at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:233)
        at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:151)
        at org.eclipse.equinox.internal.event.EventAdminImpl.dispatchEvent(EventAdminImpl.java:138)
        at org.eclipse.equinox.internal.event.EventAdminImpl.sendEvent(EventAdminImpl.java:81)
        at org.eclipse.equinox.internal.event.EventComponent.sendEvent(EventComponent.java:42)
        at org.eclipse.e4.ui.services.internal.events.EventBroker.send(EventBroker.java:55)
        at org.eclipse.e4.ui.workbench.UIEvents.publishEvent(UIEvents.java:378)
        at org.eclipse.e4.ui.workbench.UIEvents.publishEvent(UIEvents.java:347)
        at org.eclipse.e4.ui.internal.workbench.PartServiceImpl.activate(PartServiceImpl.java:731)
        at org.eclipse.e4.ui.internal.workbench.PartServiceImpl.activate(PartServiceImpl.java:684)
        at org.eclipse.e4.ui.internal.workbench.swt.AbstractPartRenderer.activate(AbstractPartRenderer.java:97)
        at org.eclipse.e4.ui.workbench.renderers.swt.ContributedPartRenderer.lambda$0(ContributedPartRenderer.java:63)
        at org.eclipse.e4.ui.workbench.renderers.swt.ContributedPartRenderer$$Lambda$236/1372855191.handleEvent(Unknown Source)
        at org.eclipse.swt.widgets.EventTable.sendEvent(EventTable.java:89)
        at org.eclipse.swt.widgets.Display.sendEvent(Display.java:4145)
        at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1055)
        at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1079)
        at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:1064)
        at org.eclipse.swt.widgets.Shell.setActiveControl(Shell.java:1517)
        at org.eclipse.swt.widgets.Shell.setActiveControl(Shell.java:1480)
        at org.eclipse.swt.widgets.Control.sendFocusEvent(Control.java:2972)
        at org.eclipse.swt.widgets.Widget.wmSetFocus(Widget.java:2234)
        at org.eclipse.swt.widgets.Control.WM_SETFOCUS(Control.java:5434)
        at org.eclipse.swt.widgets.Canvas.WM_SETFOCUS(Canvas.java:445)
        at org.eclipse.swt.widgets.Control.windowProc(Control.java:4838)
        at org.eclipse.swt.widgets.Canvas.windowProc(Canvas.java:348)
        at org.eclipse.swt.widgets.Display.windowProc(Display.java:4784)
        at org.eclipse.swt.internal.win32.OS.SetFocus(Native Method)
        at org.eclipse.swt.widgets.Control.forceFocus(Control.java:1116)
        at org.eclipse.swt.widgets.Control.setSavedFocus(Control.java:3747)
        at org.eclipse.swt.widgets.Decorations.restoreFocus(Decorations.java:781)
        at org.eclipse.swt.widgets.Decorations.WM_ACTIVATE(Decorations.java:1547)
        at org.eclipse.swt.widgets.Shell.WM_ACTIVATE(Shell.java:2202)
        at org.eclipse.swt.widgets.Control.windowProc(Control.java:4765)
        at org.eclipse.swt.widgets.Canvas.windowProc(Canvas.java:348)
        at org.eclipse.swt.widgets.Decorations.windowProc(Decorations.java:1502)
        at org.eclipse.swt.widgets.Shell.windowProc(Shell.java:2162)
        at org.eclipse.swt.widgets.Display.windowProc(Display.java:4784)
        at org.eclipse.swt.internal.win32.OS.PeekMessageW(Native Method)
        at org.eclipse.swt.internal.win32.OS.PeekMessage(OS.java:2793)
        at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3556)
        at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine$5.run(PartRenderingEngine.java:1173)
        at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:339)
        at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine.run(PartRenderingEngine.java:1062)
        at org.eclipse.e4.ui.internal.workbench.E4Workbench.createAndRunUI(E4Workbench.java:156)
        at org.eclipse.ui.internal.Workbench.lambda$3(Workbench.java:628)
        at org.eclipse.ui.internal.Workbench$$Lambda$20/1175146719.run(Unknown Source)
        at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:339)
        at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:563)
        at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:151)
        at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:155)
        at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:199)
        at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:137)
        at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:107)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:391)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:246)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:659)
        at org.eclipse.equinox.launcher.Main.basicRun(Main.java:595)
        at org.eclipse.equinox.launcher.Main.run(Main.java:1501)

mihnita commented 5 years ago

"I Generate some log messages (couple hundred lines??) with ansi colors"

Thank you Mike. Any chance you can "fake" some of that output? A simple app that outputs a bunch of hard-coded strings from an array, again and again?

I am trying to figure out how to trigger it. Very long strings, with a few colors? Or the number of colors is what matters, not really the length of the strings? Lots of strings, or few strings but very long? Stuff like that...

Mihai

youngm commented 5 years ago

@mihnita This simple application duplicates it for me. Again my system details are: Windows 10 STS 4 (latest) Theme: Dark

$ java -version
java version "1.8.0_191"
Java(TM) SE Runtime Environment (build 1.8.0_191-b12)
Java HotSpot(TM) 64-Bit Server VM (build 25.191-b12, mixed mode)

To duplicate run this application then try to do stuff with the console (scroll, maximize, etc). Hopefully the utf-8 encoded file preserves the ansi coding.

TestConsole.zip

mihnita commented 5 years ago

I did some digging on this (a while ago) I wanted to write something longer, like a blog post, but it looks like it will not happen (too busy / lazy :-)

But basically in black mode Eclipse does double, in some cases triple calls on the coloring callback compared to the white theme. I don't know why, but the only fix on my side would be heavy caching. I've tried that before (because of the scrolling bug https://github.com/mihnita/ansi-econsole/issues/3) The trouble with that is that I don't have a good "key" for the cashing. There is no fixed info about a line. There is a "line number" in the callback, but it changes as the buffer drops lines :-(

I'll take a shot at that caching problem once in a while, because it bugs me... I waste a few days, then I give up. I'll probably try again. But I have no quick solution. Sorry

youngm commented 5 years ago

Thanks @mihnita for the update. Glad you were able to duplicate.

Your problem statement peeked my interest. I know very little about eclipse development so if I'm just talking nonsense feel free to ignore me.

I'm assuming that the "coloring callback" includes the line of text to be colored and the computational effort to color that line over and over is what makes things slow? Would it be possible to use a fast somewhat unique hash of the line contents itself as the key for the colored version?

Wutklumpen commented 5 years ago

Hey, this problem persists in my company also. I add two Stacktraces, which might help. stacktraceB.txt stacktraceA.txt

mihnita commented 5 years ago

Thank you Wutklumpen, Unfortunately it does not help much.

I can confirm it is happening, and I also know why (see my comment on Apr 14)

"But basically in black mode Eclipse does double, in some cases triple calls on the coloring callback compared to the white theme."

I don't have a good solution. The hash (youngm's idea) works for longer, relatively complicated lines. But if there are lots of similar lines then it does not work.

youngm commented 5 years ago

@mihnita Interesting. I'd think that my idea would work even better if there are lots of similar lines because your cache would be much smaller in that case. Must be something with the API I'm not aware of.

kdvolder commented 4 years ago

But basically in black mode Eclipse does double, in some cases triple calls on the coloring callback compared to the white theme

Sounds like this is something that should be raised as a bug against Eclipse platform?

mihnita commented 4 years ago

Spent some more time on this. Caching does not help, even with many identical lines, because the result depends on the attributes from previous lines.

Imagine that we have this line again and again:

.....<start_bold>......<end_bold>.....

One would think that the result would be the same every time. But it is not:

.....<red>..... 
.....<start_bold>......<end_bold>.....  // => red, red_bold, red
.....<italic>..... 
.....<start_bold>......<end_bold>.....  // => red_italic, red_bold_italic, red_italic
.....<background_blue>..... 
.....<start_bold>......<end_bold>.....  // => red_bk_blue_italic, red_bk_blue_bold_italic, red_bk_blue_italic

mihnita commented 4 years ago

Hope this is improved in version 1.4.0.202001252332.

I did a big refactoring, something that might allow caching later on (but with a price in memory, of course)

The speed should be better now, but it might also be slower in some conditions.

====

When the output buffer was small Eclipse was optimizing the output and doing a "jump" (for example showing lines 1-100, then jump to show directly line 1000)

Fair enough. What's the point to get the colors for lines below 900 if they can't fit in the console buffer and are dropped anyway.

But that resulted in incorrect rendering. Think an escape setting the color to red in line 500. My coloring callback was never invoked, so there was no way to know that lines 2000-2100 are red. But now I am inspecting all lines

Anyway... the rendering should be a lot more accurate, with a speed price.

But I think that the new approach allows me to associate the cached results with the proper lines.

marcelopbarros commented 4 years ago

This bug has been bothering me for a long time and my solution has always been to disable Ansi Console. But, after finding this issue, I tried something different that I think could help. In my tests, if I choose Dark [Linux] theme, even using Windows, the console seems to work just as well as the Light theme.

That's what I used to check the performance:

I printed the lines using the simple TestConsole proposed by @youngm here;
I maximized the console view and return to the original size (double click);
I scrolled up and down.

The details of my system are:

Windows 10 1809
Spring Tool Suite 4.5.1.RELEASE (202001211336)

I'm still looking for drawbacks to using Dark [Linux] on Windows. I hope this information can help in any way to solve this problem. Cheers!

mihnita commented 4 years ago

Thanks Marcelo (and all others contributing :-)

The last release should make things a bit better, because I've added caching, and only calculate things once. (last night, so 1.4.0.20200131..., darn, I should have "bumped" to 1.4.1 :-)

I've added caching, and I think that the Dark on Windows is as fast / slow as the Light mode. They are both quite a bit slower than the Linux one, and a lot slower than no plugin at all.

I didn't notice any performance difference between Dark and Dark (Linux). I think that Dark Linux has a certain class of labels using black text, hard to read on dark background (selected list / menu items, I think). Other than that, noting major. But no performance benefit that I could notice (Win 10, Eclipse 2019-12)

I've profiled things, and two of the bigger hotspots seem to be in some Eclipse methods. I will try bypassing the Eclipse Document Position mechanism completely. Will see how it goes...

Thanks for the patience :-) Mihai

mihnita commented 4 years ago

I've run some tests with the latest version (1.4.2).

Conditions:

The console had a buffer of 1.000.000 characters, "Interpret ASCII control characters" on, and "Interpret Carriage Return (\r) as control character" on.
I've run a modified version of the tests in TestConsole.zip several times.
- 4 runs of 10K loops, and 5 times 1K loops
- Each loop outputs 2 lines, an error an a warning.
- At the beginning of each line I attached the loop number, so that the lines are not identical.
Used System.nanoTime(), and the result is the (endTime-starTime)/1000000
All on Windows 10, JDK 8
Did an Eclipse restart and a few "dry runs" after each setting change to "warm things up", make sure Eclipse finished indexing, etc.
These are "first rendering results". Didn't do any navigation up/down in the console. Just rendered once.

The exact conditions probably don't not really matter that much. The point is: all the conditions were identical between runs, only changed color theme and the plugin enabled / disabled / uninstalled.

Results:

Dark, enabled        : 2288 2278 2217 2215    510 496 497 506 516
Dark, disabled       : 1203 1196 1219 1176    330 328 323 324 326
Dark, not inst       : 1204 1201 1193 1201    295 295 305 293 291

Dark Linux, enabled  : 1501 1543 1503 1537    313 305 320 306 308
Dark Linux, disabled :  980  981  952  990    311 325 312 309 310
Dark Linux, not inst :  977  994  941 1013    278 275 283 275 285

Light, enabled       : 1480 1495 1488 1476    304 307 306 303 306
Light, disabled      :  932  818  950  882    310 309 307 310 310
Light, not inst      :  980 1005  996 1013    286 277 280 276 274

Dark, enabled, 1.4.3 : 2237 2250 2219 2236    503 473 472 495 491
Dark, enabled, 1.3.5 : 1664 1653 1674 1671    513 499 506 502 500

What I think this shows:

There is indeed a measurable difference between the Dark theme and the Dark Linux theme
The Dark theme is clearly slower than the Dark Linux theme even with the plugin uninstalled
There is a very small difference between the Light theme and the Dark Linux theme
The plugin disabled adds no real overhead compared to the plugin uninstalled
"The big refactoring" for 1.4.x makes things slower :-( for the "first rendering"

Compared to 1.3.5

Things are faster in 1.4.x when navigating the console (scrolling up and down) because the refactoring made possible to cache the results. But that is not captured in these measurements.

The differences between 1.4.2 and 1.3.5 are also insignificant for relatively small numbers of lines (2K lines), when they all fit in the console.

Eclipse optimizes the callback to format the lines. Let's say the console can fit 100 lines, but you output 1000. The callback is invoked for lines 1..100, then 900...1000. So the callback only gets to process 200 lines. This also means that if line 200 changes a color that was completely missed. With the refactoring I get to scan the complete document for regexp, all the lines. This makes things slower.

mihnita commented 4 years ago

BTW, I've tried this:

I will try bypassing the Eclipse Document Position mechanism completely.

I don't see any significant improvements.

adamitj commented 4 years ago

I'm using the latest version up to date of Spring STS 4.5.1.RELEASE under the latest Windows 10 64-bit and Correto JDK 1.8. The problem still exists only with Dark theme.

As @marcelopbarros pointed out switching to Dark [Linux] solves the issue entirely.

As a matter of fact, I compared all files under <workspace>\.metadata\.plugins\org.eclipse.core.runtime\.settings using Kdiff3 searching for any changes, but it seems that Dark and Dark [Linux] are exactly equals. There is no difference in these files neither I can see any difference using the IDE.

I'm not into the plugin code, but it seems that there is some buggish code inside eclipse, not in the plugin.

Not sure if it can be classified like a workaround, but the permanent fix is to use Dark [Linux] theme:

mihnita commented 4 years ago

Even if diffing the theme files shows that Dark and Dark Linux are identical, there are for sure code differences.

Look at the results with my plugin uninstalled:

Dark, not inst       : 1204 1201 1193 1201    295 295 305 293 291
Dark Linux, not inst :  977  994  941 1013    278 275 283 275 285
Light, not inst      :  980 1005  996 1013    286 277 280 276 274

It's pretty clear that Dark is slower, and that Dark Linux is almost the same as Light.

And since these "slowness" of the Dark mode is visible without my plugin, it is clearly an Eclipse issue.

mihnita commented 4 years ago

@MichielVerloop

Running the same program in the windows 10 command prompt (with the registry enabled to display the colors) doesn't cause any delays.

Well... it will never be as fast as a console, because the way Eclipse deals with it. You can completely uninstall my plugin and it will still be slower than a "real console"

The cause may be related to excessive use of colors.

Yes, and no... This one has a lot more colors: https://marketplace.eclipse.org/sites/default/files/TrueColor.jpg It is slow, but it does not get to "not responding" message.

Can you try the "Light", "Dark [Linux]" themes? And maybe even with the plugin disabled? See the comment above. The "Dark" theme on Windows is slower than the others, plugin or not.
Can you please copy the output, with escapes, put it in a file and attach it to this bug? It really does not look like a lot of colors... (there is an icon next to the enable/disable one that does "Copy text with escapes", the normal select all + copy in console strips the escapes)

Thank you, Mihai

MichielVerloop commented 4 years ago

This one has a lot more colors: https://marketplace.eclipse.org/sites/default/files/TrueColor.jpg

I neglected to mention that the program will print hundreds (sometimes thousands) of the boards to the point where it overflows the console buffer.

Can you try the "Light", "Dark [Linux]" themes? And maybe even with the plugin disabled? See the comment above. The "Dark" theme on Windows is slower than the others, plugin or not.

Attached here is a zip containing three snapshots of the output stitched together, they should overflow the buffer. The zip also contains a simple main function that takes 100 ms to print each line, which is to simulate the delays between the prints of each board in the original program.

Disabling the plugin makes the prints instant - every 100ms I can expect a line to be printed.
Enabling the plugin on Dark mode and expanding the console output such that it takes up the entire screen provides a number of updates every few seconds. After alt-tabbing in and out a few times to check back on it and write this, I start having to wait up to a few seconds for it to show eclipse, and when it does, it no longer responds. I've also had it flicker in and out of existence to the point where it no longer shows up in task manager (although it does show up in details). I can provide a video of this if that is deemed helpful.
Enabling the plugin on Dark [Linux] mode is definitely faster and allows me to actually take actions while the program is running with semi-reasonable delays. After alt-tabbing a few times, expanding and minimizing the console, I cannot get not-responding shenanigans. Its printing speed is hardly ever delayed beyond the coded 100ms/line.

vogella commented 4 years ago

2020-06 is much faster in its CSS theme. Maybe this fixes also this issue?

vogella commented 4 years ago

To test: download the latest I-build from https://download.eclipse.org/eclipse/downloads/

mihnita commented 4 years ago

2/020-06 is much faster in its CSS theme. Maybe this fixes also this issue? I've already tested 2020-06 (M1) to make sure it the plugin still works (it does), but did not check the performance.

Now I took M3 and measured the performance. And it is bad! The whole Eclipse Console output got about 5-6 times slower overall, with or without plugin. I will also try RC1, looks like it is out. But I am not too optimistic for something to change "big time" so late in the game :-(

First (draft) numbers

Running on 2020-03:

Dark: 628
Dark (Linux): 368
Light: 360
Plugin disabled: 383
Plugin uninstalled: 364

Running on 2020-06 M3:

Dark: 1854
Light: 1828
Disabled (dark): 1860
Disabled (light): 1844
Plugin uninstalled: 1822

And there are no significant differences between plugin / no plugin (that was the same before, except for Dark) Dark Linux is gone, so no more workaround.

Notes Tested on one machine only, Win 10 x64, Oracle JDK 1.8.0_251 x64, MS antivirus real time protection disabled.

The numbers are ms, running the same test several times on the same configuration, to "warm up" the jvm :-) The results vary a bit every time, in the +/- 10 ms. That's why you might see "weird" things like faster result with the plugin on light mode (360) than with the plugin disabled (364).

It basically means "it's about the same"

The code (basically the one from *youngm, Dec 2018):

private static void issue27() {
  long startTime = System.currentTimeMillis();
  for (int i = 0; i < 1000; i++) {
    System.out.println(i + "  \033[2m2018-12-22T10:18:04.496-07:00\033[0;39m \033[32m INFO\033[0;39m "
        + "\033[35m33536\033[0;39m \033[2m---\033[0;39m \033[2m[  restartedMain]\033[0;39m "
        + "\033[36msome.org.Main                           \033[0;39m "
        + "\033[2m:\033[0;39m This is an info message");
    System.out.println(i + "  \033[2m2018-12-22T10:18:04.496-07:00\033[0;39m \033[31mERROR\033[0;39m "
        + "\033[35m33536\033[0;39m \033[2m---\033[0;39m \033[2m[  restartedMain]\033[0;39m "
        + "\033[36msome.org.Main                           \033[0;39m "
        + "\033[2m:\033[0;39m This is an error message.");
  }
  long stopTime = System.currentTimeMillis();
  System.out.println("DONE: " + (stopTime - startTime));
}

mihnita commented 4 years ago

OK, the news are not so bad.

Testing to see if there is some workaround I "tinkered" with the Eclipse console settings.

"Interpret ASCII control characters" makes no visible difference

But "Limit console output disabled" did. By default it is 80000. If I disable it, or I change it to 1000000 the numbers go down to about 640 for both Light and Dark (no plugin installed).

The setting was 1000000 on my 2020-03 Eclipse, which I used for comparison. So when I was getting 350 vs 1850 I was not comparing apples to apples.

The performance still got worse, but only (a bit less than) 2 times worse. The Light (360) went to the same level as the old Dark (630), and Dark (Linux is gone).

On the other side the various tests show that the plugin adds little to no overhead. Of course, I can imagine that the heavier the use of escapes the slower it would get. But I didn't check (yet).

mihnita commented 3 years ago

At this point the performance with the plugin uninstalled / disabled / enabled are very similar, for both light / dark themes.

Eclipse 2020-12 adds a new Console setting, "word wrap" The performance of that is horrible, more than 20 times slower for some use cases (like the code from youngm, Dec 2018).

I've added some checks and if the Console settings are known to be performance bottlenecks I warn, and explain where to change them. I don't have the right to change them myself, as they don't belong to my plugin.

So I will close this bug, I don't think there is much else I can do. But I will keep an eye on performance for each release.

qngl commented 2 years ago

No matter Light or Dark, when enabling the plugin, selecting on logs are very slow. It is fast if the plugin is disabled.

marekpulka commented 2 years ago

In my case I use:

STS4 (4.13.1)
Darkest Dark Theme with Devstyle (2021.5.26) - Installed from Eclipse Marketplace as it was popular so I wanted to check it out.
Ansi Console (1.4.6.202112080311)
couple of more but I assume unrelated

I get very bad experience (lag + high cpu) when I scroll even a handful (~100) of lines in console view

I profiled and looks like a couple of methods are called that eventually lead to many invocations of methods responsible to update the view. org.eclipse.equinox.launcher.Main.main calls 2,774 x times: com.codeaffine.eclipse.swt.widget.scrollable.WatchDog.run

Here is more detailed call tree: darkest-codeaffine-watchdog-call-tree

at org.eclipse.swt.widgets.Label.setBounds I don't see what is happening due the filtering in JProfiler profiling session.

I will see if uninstalling Darkest Dark Theme with Devstyle or changing the theme only from Darkest Dark Theme with Devstyle - darkest to default will improve it. I will check if I will stop to see the above heavy calls from org.eclipse.equinox.launcher.Main.main to classes packaged in codeaffine. These packages are in those plugins: codeaffine-packages

The number of invocation of 2,774 x times: com.codeaffine.eclipse.swt.widget.scrollable.WatchDog.run seems high to me as I was really very little scrolling the console view.

mihnita / ansi-econsole

Performance issue with official Dark Theme #27