Protege UI is very slow with the recent java

[ykazakov]

• Run Protege (platform independent version),
• Open the pizza ontology,
• go to the class hierarchy
• iterate over subclasses of Pizza using the cursor

For me Protege jumps to the next subclass after a significant delay (about half a second).
Previously it was almost instant.

I did some investigation. It turns out the problem happens with the recent version of java (1.8.0_144 and 1.8.0_152 from today). It works swiftly with java 1.8.0_77 and before:

    1.8.0_152, x86_64:	"Java SE 8"	/Library/Java/JavaVirtualMachines/jdk1.8.0_152.jdk/Contents/Home
    1.8.0_144, x86_64:	"Java SE 8"	/Library/Java/JavaVirtualMachines/jdk1.8.0_144.jdk/Contents/Home
    1.8.0_77, x86_64:	"Java SE 8"	/Library/Java/JavaVirtualMachines/jdk1.8.0_77.jdk/Contents/Home
    1.8.0_60, x86_64:	"Java SE 8"	/Library/Java/JavaVirtualMachines/jdk1.8.0_60.jdk/Contents/Home
    1.7.0_51, x86_64:	"Java SE 7"	/Library/Java/JavaVirtualMachines/jdk1.7.0_51.jdk/Contents/Home
    1.7.0_40, x86_64:	"Java SE 7"	/Library/Java/JavaVirtualMachines/jdk1.7.0_40.jdk/Contents/Home
    1.6.0_65-b14-462, x86_64:	"Java SE 6"	/Library/Java/JavaVirtualMachines/1.6.0_65-b14-462.jdk/Contents/Home
    1.6.0_65-b14-462, i386:	"Java SE 6"	/Library/Java/JavaVirtualMachines/1.6.0_65-b14-462.jdk/Contents/Home

Here is what I see in the profiler (VisualVM, Hot Spots, sorted by CPU time) for java 1.8.0_152:

As you can see, over 90% of CPU time is spent on getting the mouse position.

In comparison, here is the same picture for java 1.8.0_77:

Possibly a java bug?

Running on macOS 10.13 (17A405)

[ykazakov]

I did some further testing. Seems to be a java bug specific to macOS. The problem first appears in Java 1.8.0_131. Works fine for me with the previous release 1.8.0_121. The following part of the release notes is probably relevant:

client-libs/java.awt
Introduced a new window ordering model
On the OS X platform, the AWT framework used native services to implement parent-child relationship for windows. That caused some negative visual effects especially in multi-monitor environments. To get rid of the disadvantages of such an approach, the new window ordering model, which is fully implemented at the JDK layer, was introduced. Its main principles are listed below:

A window should be placed above its nearest parent window.
If a window has several child windows, all child windows should be located at the same layer and the window from the active window chain should be ordered above its siblings.
Ordering should not be performed for a window that is in an iconified state or when the transition to an iconified state is in progress.

These rules are applied to every frame or dialog from the window hierarchy that contains the currently focused window.
See JDK-8169589

[ykazakov]

Here is a test to reproduce the problem without Protege:

package org.test.java;

import java.awt.Dimension;
import java.awt.GridLayout;
import java.awt.Point;
import java.awt.event.ActionEvent;
import java.awt.event.ActionListener;

import javax.swing.BorderFactory;
import javax.swing.JFrame;
import javax.swing.JPanel;
import javax.swing.JTextArea;
import javax.swing.Timer;

public class MousePositionTest extends JPanel {

	JTextArea textArea;
	Timer timer;

	public static void main(String[] args) {
		javax.swing.SwingUtilities.invokeLater(new Runnable() {
			@Override
			public void run() {
				JFrame frame = new JFrame("MousePositionTest");
				frame.setDefaultCloseOperation(JFrame.EXIT_ON_CLOSE);
				frame.setContentPane(new MousePositionTest());
				frame.pack();
				frame.setVisible(true);
			}
		});
	}

	public MousePositionTest() {
		super(new GridLayout(0, 1));
		textArea = new JTextArea();
		textArea.setEditable(false);
		add(textArea);
		setPreferredSize(new Dimension(400, 400));
		setBorder(BorderFactory.createEmptyBorder(20, 20, 20, 20));
		timer = new Timer(1000, new ActionListener() {

			@Override
			public void actionPerformed(ActionEvent e) {
				long time = System.currentTimeMillis();
				Point pos = null;
				for (int i = 1; i < 10; i++) {
					pos = getMousePosition();
				}
				time -= System.currentTimeMillis();
				textArea.setText("pos = " + pos + " [" + -time + "ms]");
			}
		});
		timer.start();
	}

}

For the previous version of java, I see about 1-2 milliseconds for 10 calls of getMousePosition(). With the recent version it is about 200 milliseconds. Filed a java bug report. Will post here a link when it is accepted.

[ykazakov]

Here is the link to the java bug: JDK-8189934

[matthewhorridge]

Brilliant - thanks a lot @ykazakov. I'll have a look at this as soon as I can and see if I can implement some kind of sensible workaround.

[ykazakov]

I think a sensible workaround would be not to include any recent JRE in the version for macOS until this bug is fixed. I don't think the platform-independent version is used very often, but I could be wrong.

[matthewhorridge]

@ykazakov this seems stale now. I'll close this issue.

[ykazakov]

@matthewhorridge this could be a deal breaker for #822. It does not look like it has been fixed yet in Java 11. Worth at least keeping eye on this issue.

[matthewhorridge]

@ykazakov thanks so much for the heads up. Really appreciate it.

[ykazakov]

Just checked: as of java 11.0.2 this issue is not fixed yet.
java version "11.0.2" 2018-10-16 LTS
Java(TM) SE Runtime Environment 18.9 (build 11.0.2+7-LTS)
Java HotSpot(TM) 64-Bit Server VM 18.9 (build 11.0.2+7-LTS, mixed mode)

[matthewhorridge]

Thanks so much for checking this @ykazakov

[matthewhorridge]

Reopened this issue because this is still a concern

[matthewhorridge]

Seems that u121 is okay but after that, the performance of getMousePosition causes a little lag in the UI. Just wondering whether this is a real problem vs upgrading to the latest Java for security benefits.

[ykazakov]

Frankly, I find the lag to be a big annoyance. I did not anticipate that it would take so long to fix it. Perhaps something could be improved programmatically, e.g., by caching the mouse location. But even 20ms per mouse location query is a lot. Are there any serious security issues that have been fixed after u121?

[matthewhorridge]

Yeah, after more testing, it is annoying. I've just committed some code that adds a cache and this improves things somewhat.

[matthewhorridge]

Are there any serious security issues that have been fixed after u121?

I'm not sure about this. I want to update Java to fix the problem with LetsEncrypt certificates

[matthewhorridge]

@ykazakov there's a bare bones platform independent Protege build here. Do you think this performance is acceptable?

[ykazakov]

I do not notice much improvements. Seems to be as slow as before. 0.5-1 second jumps between subclasses of NamedPizza.

[matthewhorridge]

Thanks for looking. Hmmmm okay, I'm seeing much better performance than this

[ykazakov]

The version of java I am using:
java version "1.8.0_192"
Java(TM) SE Runtime Environment (build 1.8.0_192-b12)
Java HotSpot(TM) 64-Bit Server VM (build 25.192-b12, mixed mode)

[matthewhorridge]

I'm on (for testing)

java version "1.8.0_201"
Java(TM) SE Runtime Environment (build 1.8.0_201-b09)
Java HotSpot(TM) 64-Bit Server VM (build 25.201-b09, mixed mode)

[ykazakov]

will try that

[matthewhorridge]

Okay, I wasn't testing with pizza.owl, but when I do, I see terrible performance.

[matthewhorridge]

Will stick with u121 max

[ykazakov]

You can still update jre for windows and linux. As far as I understand, this is only a mac issue.

[matthewhorridge]

I'll update to u121 for all platforms.... don't want more variation for bug reporting.

[matthewhorridge]

@ykazakov thanks for all of your help with this

[ykazakov]

@matthewhorridge I checked your workaround with caching and it is actually working! You just cached the wrong method ;-)

[matthewhorridge]

@ykazakov Thanks a lot for the PR. I think performance is good enough now... upgrading past Java 8u121 should be possible (i.e. to Java 11 OpenJDK).

[ykazakov]

@matthewhorridge I think so. I will do a bit more testing, but I think this ticket can be closed for now.