1.3 second UI freezes in at org.eclipse.swt.widgets.Table.setItemCount(Table.java:3652)

[vogella]

Environment:

• Select the platforms on which the behavior is seen.
  [x] All OS
  [ ] Windows
  [ x] Linux
  [ ] macOS

Eclipse SDK
Version: 2022-06 (4.25)
Build id: I20220612-1800
OS: Linux, v.5.15.0-37-generic, x86_64 / gtk 3.24.33, WebKit 2.36.3
Java vendor: Eclipse Adoptium
Java runtime version: 17.0.3+7
Java version: 17.0.3

I see long UI freezes coming from the Git History view with regards to Table.setItemCount. Looks like a lot is happening in this method, like removing all items, etc. Can this be improved?

Method code:

public void setItemCount (int count) {
	checkWidget ();
	count = Math.max (0, count);
	if (count == itemCount) return;
	boolean isVirtual = (style & SWT.VIRTUAL) != 0;
	if (!isVirtual) setRedraw (false);
	remove (count, itemCount - 1);
	int length = Math.max (4, (count + 3) / 4 * 4);
	TableItem [] newItems = new TableItem [length];
	System.arraycopy (items, 0, newItems, 0, itemCount);
	items = newItems;
	if (isVirtual) {
		long iter = OS.g_malloc (GTK.GtkTreeIter_sizeof ());
		if (iter == 0) error (SWT.ERROR_NO_HANDLES);
		for (int i=itemCount; i<count; i++) {
			GTK.gtk_list_store_append (modelHandle, iter);
		}
		OS.g_free (iter);
		itemCount = count;
	} else {
		for (int i=itemCount; i<count; i++) {
			new TableItem (this, SWT.NONE, i, true);
		}
	}
	if (!isVirtual) setRedraw (true);
}

Stack Trace

	at org.eclipse.swt.internal.gtk.GTK.gtk_list_store_clear(Native Method)
	at org.eclipse.swt.widgets.Table.removeAll(Table.java:2812)
	at org.eclipse.swt.widgets.Table.remove(Table.java:2703)
	at org.eclipse.swt.widgets.Table.setItemCount(Table.java:3652)
	at org.eclipse.jface.viewers.TableViewer.doSetItemCount(TableViewer.java:231)
	at org.eclipse.jface.viewers.AbstractTableViewer.internalVirtualRefreshAll(AbstractTableViewer.java:646)
	at org.eclipse.jface.viewers.AbstractTableViewer.internalRefresh(AbstractTableViewer.java:620)
	at org.eclipse.jface.viewers.AbstractTableViewer.internalRefresh(AbstractTableViewer.java:610)
	at org.eclipse.jface.viewers.AbstractTableViewer.lambda$0(AbstractTableViewer.java:572)
	at org.eclipse.jface.viewers.AbstractTableViewer$$Lambda$1107/0x00000008015751b8.run(Unknown Source)
	at org.eclipse.jface.viewers.StructuredViewer.preservingSelection(StructuredViewer.java:1398)
	at org.eclipse.jface.viewers.StructuredViewer.preservingSelection(StructuredViewer.java:1359)
	at org.eclipse.jface.viewers.AbstractTableViewer.inputChanged(AbstractTableViewer.java:572)
	at org.eclipse.jface.viewers.ContentViewer.setInput(ContentViewer.java:282)
	at org.eclipse.jface.viewers.StructuredViewer.setInput(StructuredViewer.java:1632)
	at org.eclipse.egit.ui.internal.history.GitHistoryPage.clearViewers(GitHistoryPage.java:1835)
	at org.eclipse.egit.ui.internal.history.GitHistoryPage.lambda$6(GitHistoryPage.java:2558)
	at org.eclipse.egit.ui.internal.history.GitHistoryPage$$Lambda$1415/0x0000000801739d08.run(Unknown Source)
	at org.eclipse.egit.core.UnitOfWork.execute(UnitOfWork.java:96)
	at org.eclipse.egit.ui.internal.history.GitHistoryPage.initAndStartRevWalk(GitHistoryPage.java:2512)
	at org.eclipse.egit.ui.internal.history.GitHistoryPage.inputSet(GitHistoryPage.java:2132)
	at org.eclipse.egit.ui.internal.history.GitHistoryPage.inputSet(GitHistoryPage.java:1991)
	at org.eclipse.team.ui.history.HistoryPage.setInput(HistoryPage.java:54)
	at org.eclipse.egit.ui.internal.history.GitHistoryPage.setInput(GitHistoryPage.java:1981)
	at org.eclipse.team.internal.ui.history.GenericHistoryView.getPageRec(GenericHistoryView.java:650)
	at org.eclipse.ui.part.PageBookView.partActivated(PageBookView.java:694)
	at org.eclipse.team.internal.ui.history.GenericHistoryView.showHistoryPageFor(GenericHistoryView.java:626)
	at org.eclipse.team.internal.ui.history.GenericHistoryView.showLastSelectedElement(GenericHistoryView.java:565)
	at org.eclipse.team.internal.ui.history.GenericHistoryView$1.selectionChanged(GenericHistoryView.java:406)
	at org.eclipse.ui.internal.e4.compatibility.SelectionService.notifyListeners(SelectionService.java:266)
	at org.eclipse.ui.internal.e4.compatibility.SelectionService.handlePostSelectionChanged(SelectionService.java:123)
	at org.eclipse.ui.internal.e4.compatibility.SelectionService.lambda$2(SelectionService.java:78)
	at org.eclipse.ui.internal.e4.compatibility.SelectionService$$Lambda$344/0x0000000801063780.selectionChanged(Unknown Source)
	at org.eclipse.e4.ui.internal.workbench.SelectionAggregator$3.run(SelectionAggregator.java:163)
	at org.eclipse.core.runtime.SafeRunner.run(SafeRunner.java:45)
	at org.eclipse.e4.ui.internal.workbench.SelectionAggregator.notifyPostListeners(SelectionAggregator.java:160)
	at org.eclipse.e4.ui.internal.workbench.SelectionAggregator$6.lambda$0(SelectionAggregator.java:250)
	at org.eclipse.e4.ui.internal.workbench.SelectionAggregator$6$$Lambda$1089/0x0000000801544480.run(Unknown Source)
	at org.eclipse.e4.core.contexts.RunAndTrack.runExternalCode(RunAndTrack.java:59)
	at org.eclipse.e4.ui.internal.workbench.SelectionAggregator$6.changed(SelectionAggregator.java:250)
	at org.eclipse.e4.core.internal.contexts.TrackableComputationExt.update(TrackableComputationExt.java:105)
	at org.eclipse.e4.core.internal.contexts.EclipseContext.runAndTrack(EclipseContext.java:338)
	at org.eclipse.e4.ui.internal.workbench.SelectionAggregator.track(SelectionAggregator.java:236)
	at org.eclipse.e4.ui.internal.workbench.SelectionAggregator.setPart(SelectionAggregator.java:114)
	at jdk.internal.reflect.GeneratedMethodAccessor57.invoke(Unknown Source)
	at java.base@17.0.3/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base@17.0.3/java.lang.reflect.Method.invoke(Method.java:568)
	at org.eclipse.e4.core.internal.di.MethodRequestor.execute(MethodRequestor.java:58)
	at org.eclipse.e4.core.internal.contexts.ContextObjectSupplier$ContextInjectionListener.update(ContextObjectSupplier.java:95)
	at org.eclipse.e4.core.internal.contexts.TrackableComputationExt.update(TrackableComputationExt.java:103)
	at org.eclipse.e4.core.internal.contexts.EclipseContext.processScheduled(EclipseContext.java:356)
	at org.eclipse.e4.core.internal.contexts.EclipseContext.set(EclipseContext.java:372)
	at org.eclipse.e4.core.internal.contexts.EclipseContext.activate(EclipseContext.java:659)
	at org.eclipse.e4.core.internal.contexts.EclipseContext.activateBranch(EclipseContext.java:668)
	at org.eclipse.e4.ui.internal.workbench.PartActivationHistory.activate(PartActivationHistory.java:58)
	at org.eclipse.e4.ui.internal.workbench.PartServiceImpl.activate(PartServiceImpl.java:761)
	at org.eclipse.e4.ui.internal.workbench.PartServiceImpl.activate(PartServiceImpl.java:680)
	at org.eclipse.e4.ui.internal.workbench.PartServiceImpl.activate(PartServiceImpl.java:675)
	at org.eclipse.e4.ui.internal.workbench.PartServiceImpl.showPart(PartServiceImpl.java:1252)
	at org.eclipse.ui.internal.WorkbenchPage.showPart(WorkbenchPage.java:1247)
	at org.eclipse.ui.internal.WorkbenchPage.busyShowView(WorkbenchPage.java:1235)
	at org.eclipse.ui.internal.WorkbenchPage.lambda$11(WorkbenchPage.java:4228)
	at org.eclipse.ui.internal.WorkbenchPage$$Lambda$1439/0x00000008017077b0.run(Unknown Source)
	at org.eclipse.swt.custom.BusyIndicator.showWhile(BusyIndicator.java:74)
	at org.eclipse.ui.internal.WorkbenchPage.showView(WorkbenchPage.java:4226)
	at org.eclipse.ui.internal.WorkbenchPage.showView(WorkbenchPage.java:4208)
	at org.eclipse.ui.internal.quickaccess.providers.ViewElement.execute(ViewElement.java:93)
	at org.eclipse.ui.internal.quickaccess.QuickAccessDialog$1$$Lambda$2465/0x0000000801d72d40.run(Unknown Source)
	at org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:40)
	at org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:132)
	at org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:5000)
	at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:4480)
	at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine$5.run(PartRenderingEngine.java:1155)
	at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:338)
	at org.eclipse.e4.ui.internal.workbench.swt.PartRenderingEngine.run(PartRenderingEngine.java:1046)
	at org.eclipse.e4.ui.internal.workbench.E4Workbench.createAndRunUI(E4Workbench.java:155)
	at org.eclipse.ui.internal.Workbench.lambda$3(Workbench.java:644)
	at org.eclipse.ui.internal.Workbench$$Lambda$160/0x0000000800dd2d40.run(Unknown Source)
	at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:338)
	at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:551)
	at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:156)
	at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:152)
	at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:203)
	at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:136)
	at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:104)
	at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:402)
	at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:255)
	at java.base@17.0.3/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base@17.0.3/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base@17.0.3/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base@17.0.3/java.lang.reflect.Method.invoke(Method.java:568)
	at app//org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:659)
	at app//org.eclipse.equinox.launcher.Main.basicRun(Main.java:596)
	at app//org.eclipse.equinox.launcher.Main.run(Main.java:1467)
	at app//org.eclipse.equinox.launcher.Main.main(Main.java:1440)

[vogella]

cc @jukzi

[jukzi]

i don't have linux

[SyntevoAlex]

@vogella please surround code blocks with three backticks ```

[SyntevoAlex]

I already improved performance significantly in https://bugs.eclipse.org/bugs/show_bug.cgi?id=575787#c3
How many items are being added?

[vogella]

I already improved performance significantly in https://bugs.eclipse.org/bugs/show_bug.cgi?id=575787#c3 How many items are being added?

If I open the history view in a debug session and open eclipse.platform.ui I see that org.eclipse.jface.viewers.TableViewer.doSetItemCount(TableViewer.java:231) is called multiple times, the largest value I see it 10001 as count. Adding @tomaswolf (main EGit developer) who might share more on the logic here.

[SyntevoAlex]

I tested this snippet on my Ubuntu 22.04

final Display display = new Display();
final Shell shell = new Shell(display);
shell.setLayout (new GridLayout (1, true));

Table table = new Table(shell, SWT.VIRTUAL);
table.setLayoutData(new GridData(SWT.FILL, SWT.FILL, true, true));

shell.pack();
shell.open();

for (int i = 0; i < 100; i++) {
	if ((i % 2) == 0) {
		final long start = System.currentTimeMillis();
		{
			table.setItemCount(10_000);
		}
		final long end = System.currentTimeMillis();
		System.out.println("table.setItemCount: " + (end - start) + " ms");
	} else {
		final long start = System.currentTimeMillis();
		{
			table.setItemCount(0);
		}
		final long end = System.currentTimeMillis();
		System.out.println("table.removeAll:    " + (end - start) + " ms");
	}
}

while (!shell.isDisposed()) {
	if (!display.readAndDispatch()) {
		display.sleep();
	}
}

display.dispose();

and the results are

table.setItemCount: 48 ms
table.removeAll:    71 ms

This looks fast enough to me. So I don't think that the problem is in SWT, at least not with what I currently know.

[iloveeclipse]

@SyntevoAlex : I assume the problem is when the tree items are really created / removed before setItemCount() is called. The snippet is fast because it doesn't crate/remove any item.

[SyntevoAlex]

OK, here's a more realistic snippet:

final Display display = new Display();
final Shell shell = new Shell(display);
shell.setLayout (new GridLayout (1, true));

Table table = new Table(shell, SWT.VIRTUAL);
table.setLayoutData(new GridData(SWT.FILL, SWT.FILL, true, true));

final int[] iteration = new int[1];
table.addListener(SWT.SetData, event -> ((Item)event.item).setText("Row:" + iteration[0] + ":" + event.index));

Runnable runCreateItems = () -> {
	iteration[0]++;

	// setItemCount()
	{
		final long start = System.currentTimeMillis();
		{
			table.setItemCount(10_000);
		}
		final long end = System.currentTimeMillis();
		System.out.println("table.setItemCount: " + (end - start) + " ms");
	}

	// Force items to be cached
	{
		final long start = System.currentTimeMillis();
		{
			for (int iItem = 0; iItem < table.getItemCount(); iItem++) {
				table.getItem(iItem);
			}
		}
		final long end = System.currentTimeMillis();
		System.out.println("table.getItem:      " + (end - start) + " ms");
	}
};

Runnable runDeleteItems = () -> {
	final long start = System.currentTimeMillis();
	{
		table.setItemCount(0);
	}
	final long end = System.currentTimeMillis();
	System.out.println("table.removeAll:    " + (end - start) + " ms");
};

Button btnCreateItems = new Button(shell, 0);
btnCreateItems.setText("Create items");
btnCreateItems.addListener(SWT.Selection, e -> {
	runCreateItems.run();
});

Button btnDeleteItems = new Button(shell, 0);
btnDeleteItems.setText("Delete items");
btnDeleteItems.addListener(SWT.Selection, e -> {
	runDeleteItems.run();
});

Button btnBoth = new Button(shell, 0);
btnBoth.setText("Do both");
btnBoth.addListener(SWT.Selection, e -> {
	runDeleteItems.run();
	runCreateItems.run();
});

runCreateItems.run();

shell.setSize(300, 500);
shell.open();

while (!shell.isDisposed()) {
	if (!display.readAndDispatch()) {
		display.sleep();
	}
}

display.dispose();

When I click on Do both, the first iteration is slow (~2800ms), and since the second, the times are like:

table.removeAll:    157 ms
table.setItemCount: 149 ms
table.getItem:      12 ms

In Java, all time is spent in a single call to gtk_list_store_clear().

When native profiling, it looks like this

  - 60,96% gtk_list_store_remove
   - 60,56% g_signal_emit
    - g_signal_emit_valist
     - 60,41% signal_emit_unlocked_R
      - 60,27% g_closure_invoke
       - 60,02% gtk_tree_view_row_deleted.lto_priv.0
        - 41,05% gtk_tree_view_real_set_cursor.lto_priv.0
         - 34,59% _gtk_tree_view_accessible_add_state
          - 34,55% create_cell.lto_priv.0
           - 13,34% set_cell_data.lto_priv.0
            - 12,70% gtk_cell_area_apply_attributes
             - 12,57% g_signal_emit
              - g_signal_emit_valist
               - 12,30% _gtk_marshal_VOID__OBJECT_BOXED_BOOLEAN_BOOLEANv
                - 11,85% gtk_cell_area_box_apply_attributes
                 - 11,65% gtk_cell_area_real_apply_attributes
                  - 10,83% g_hash_table_foreach
                   - 10,69% apply_cell_attributes
                    + 5,08% g_object_set_property
                    - 1,76% fn19_5
                     - 1,70% callback
                      + 0,95% jni_CallLongMethodV
                    + 1,22% g_object_get
                    + 1,09% g_object_thaw_notify
           + 6,74% g_object_notify
           + 5,76% gtk_container_cell_accessible_update_cache
           + 5,57% gtk_renderer_cell_accessible_new
           + 0,94% gtk_accessible_set_widget
           + 0,84% gtk_container_cell_accessible_new
         + 5,59% _gtk_tree_selection_internal_select_node
         0,56% g_signal_emit_by_name
        - 15,61% _gtk_tree_view_accessible_remove
           - 13,88% iter_remove_or_steal
            - 13,84% cell_info_free
             - 5,34% g_object_unref
              + 1,85% 0x7fb2e007b122
              + 0,87% gtk_text_cell_accessible_finalize
                0,60% g_object_notify_queue_freeze.lto_priv.0
             + 3,57% gtk_container_cell_accessible_remove_child
             + 3,48% gtk_accessible_set_widget
             + 1,21% g_object_notify
           + 1,51% g_signal_emit_by_name
        + 1,35% gtk_widget_queue_resize

That is, it spends a lot of time reacting to row-deleted events. It's also related to gtk_tree_view_accessible.

[SyntevoAlex]

I can't explain why it becomes faster after first iteration.
Unfortunately I can't spend time debugging it further.