Bug 392979 - Format code on a source directory with some hundreds of files: takes ages
Summary: Format code on a source directory with some hundreds of files: takes ages
Status: RESOLVED FIXED
Alias: None
Product: Subversive
Classification: Technology
Component: Core (show other bugs)
Version: 1.0.0   Edit
Hardware: PC Windows 7
: P3 major (vote)
Target Milestone: ---   Edit
Assignee: Alexander Gurov CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2012-10-27 11:50 EDT by Mauro Molinari CLA
Modified: 2012-11-03 07:54 EDT (History)
0 users

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Mauro Molinari CLA 2012-10-27 11:50:38 EDT
Consider a project with some hundreds of Java files. Right click on the source folder and choose Source => Format.
It takes ages to complete (I'm using an Athlon 64 X2 5200+, on Win7 64 bit, 4GB RAM, solid state drive disk, Eclipse Juno SR1 64-bit).

Taking some thread dumps, the main thread shows something like this:

java.text.Collator.getStrength(Unknown Source)
   - locked java.text.RuleBasedCollator@7b869ca5
java.text.CollationElementIterator.strengthOrder(Unknown Source)
java.text.CollationElementIterator.next(Unknown Source)
java.text.RuleBasedCollator.compare(Unknown Source)
   - locked java.text.RuleBasedCollator@7b869ca5
org.eclipse.team.internal.ui.mapping.ResourceModelSorter.compareNames(ResourceModelSorter.java:32)
org.eclipse.ui.views.navigator.ResourceSorter.compare(ResourceSorter.java:98)
org.eclipse.team.svn.ui.mapping.SVNChangeSetSorter.compare(SVNChangeSetSorter.java:68)
org.eclipse.ui.navigator.CommonViewerSorter.compare(CommonViewerSorter.java:140)
org.eclipse.team.internal.ui.mapping.TeamViewerSorter.compare(TeamViewerSorter.java:69)
org.eclipse.jface.viewers.TreePathViewerSorter$1.compare(TreePathViewerSorter.java:105)
java.util.TimSort.mergeLo(Unknown Source)
java.util.TimSort.mergeAt(Unknown Source)
java.util.TimSort.mergeForceCollapse(Unknown Source)
java.util.TimSort.sort(Unknown Source)
java.util.TimSort.sort(Unknown Source)
java.util.Arrays.sort(Unknown Source)
org.eclipse.jface.viewers.TreePathViewerSorter.sort(TreePathViewerSorter.java:103)
org.eclipse.jface.viewers.AbstractTreeViewer.getSortedChildren(AbstractTreeViewer.java:639)
org.eclipse.jface.viewers.AbstractTreeViewer.updateChildren(AbstractTreeViewer.java:2643)
org.eclipse.jface.viewers.AbstractTreeViewer.internalRefreshStruct(AbstractTreeViewer.java:1923)
org.eclipse.jface.viewers.TreeViewer.internalRefreshStruct(TreeViewer.java:721)
org.eclipse.jface.viewers.AbstractTreeViewer.internalRefreshStruct(AbstractTreeViewer.java:1930)
org.eclipse.jface.viewers.TreeViewer.internalRefreshStruct(TreeViewer.java:721)
org.eclipse.jface.viewers.AbstractTreeViewer.internalRefreshStruct(AbstractTreeViewer.java:1930)
org.eclipse.jface.viewers.TreeViewer.internalRefreshStruct(TreeViewer.java:721)
org.eclipse.jface.viewers.AbstractTreeViewer.internalRefresh(AbstractTreeViewer.java:1898)
org.eclipse.jface.viewers.AbstractTreeViewer.internalRefresh(AbstractTreeViewer.java:1855)
org.eclipse.ui.navigator.CommonViewer.internalRefresh(CommonViewer.java:561)
org.eclipse.team.internal.ui.mapping.CommonViewerAdvisor$NavigableCommonViewer.internalRefresh(CommonViewerAdvisor.java:62)
org.eclipse.jface.viewers.StructuredViewer$8.run(StructuredViewer.java:1535)
org.eclipse.jface.viewers.StructuredViewer.preservingSelection(StructuredViewer.java:1443)
org.eclipse.jface.viewers.TreeViewer.preservingSelection(TreeViewer.java:403)
org.eclipse.jface.viewers.StructuredViewer.preservingSelection(StructuredViewer.java:1404)
org.eclipse.jface.viewers.StructuredViewer.refresh(StructuredViewer.java:1533)
org.eclipse.jface.viewers.ColumnViewer.refresh(ColumnViewer.java:548)
org.eclipse.ui.navigator.CommonViewer.refresh(CommonViewer.java:353)
org.eclipse.ui.navigator.CommonViewer.refresh(CommonViewer.java:510)
org.eclipse.jface.viewers.StructuredViewer.refresh(StructuredViewer.java:1465)
org.eclipse.team.svn.ui.mapping.SVNChangeSetContentProvider$3.run(SVNChangeSetContentProvider.java:721)
org.eclipse.swt.widgets.RunnableLock.run(RunnableLock.java:35)
org.eclipse.swt.widgets.Synchronizer.runAsyncMessages(Synchronizer.java:135)
   - locked org.eclipse.swt.widgets.RunnableLock@1e425c9d
org.eclipse.swt.widgets.Display.runAsyncMessages(Display.java:4144)
org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3761)
org.eclipse.jface.operation.ModalContext$ModalContextThread.block(ModalContext.java:173)
org.eclipse.jface.operation.ModalContext.run(ModalContext.java:388)
org.eclipse.jface.dialogs.ProgressMonitorDialog.run(ProgressMonitorDialog.java:507)
org.eclipse.jdt.internal.ui.refactoring.RefactoringExecutionHelper.perform(RefactoringExecutionHelper.java:191)
org.eclipse.jdt.internal.corext.refactoring.RefactoringExecutionStarter.startCleanupRefactoring(RefactoringExecutionStarter.java:245)
org.eclipse.jdt.internal.ui.actions.CleanUpAction.performRefactoring(CleanUpAction.java:91)
org.eclipse.jdt.internal.ui.actions.CleanUpAction.runOnMultiple(CleanUpAction.java:207)
org.eclipse.jdt.internal.ui.actions.CleanUpAction.run(CleanUpAction.java:110)
org.eclipse.jdt.ui.actions.FormatAllAction.run(FormatAllAction.java:112)
[...]

Apart from the first lines that can obviously change from dump to dump, it's evident that SVNChangeSetContentProvider is issuing a lot of refreshes on the navigator views: why is this happening? Consider that my source folder is collapsed when I invoke the action on the source folder.

Eclipse seems to be frozen, although it can complete the operation in the end (after many minutes). It's even suspicious the fact that the period in which Eclipse seems to hang is AFTER the actual format operation has been completed!

Using Subversive 1.0.0.I20121013-1700, SVNKit connector 1.7.5v1 version 3.0.0.I20121013-1700.
Comment 1 Alexander Gurov CLA 2012-11-02 14:00:49 EDT
I've tried to format a folder with 365 files in different hierarchy levels in total, but everything went fine. My configuration is Core2 Duo 2.8, 3Gb RAM, HDD Samsung 320Gb (not the fastest thing, actually :) ), WinXP 32bit.
I've found a performance issue in the SVNChangeSetSorter but it does seem minor enough to try searching for something else. SVNChangeSetContentProvider calls refresh only once (and just for UI, not the resource tree itself).

Is it possible for you to describe the situation more precisely? For example:
1) how much files were changed by code format (approximately, in my case there were around 180 files modified)?
2) what views were shown in the Eclipse IDE? (Navigator, Package Explorer, Synchronize etc.)
3) In which one view exactly code format was called (Navigator, Package Explorer or something else)?
4) Was there some changesets created where the project resources were included?

P.S.
Also is it possible that the time was actually taken by the build process? Or is this happened after build process was finished already?
Comment 2 Mauro Molinari CLA 2012-11-02 15:51:49 EDT
(In reply to comment #1)
> Is it possible for you to describe the situation more precisely? For example:
> 1) how much files were changed by code format (approximately, in my case
> there were around 180 files modified)?

They were more than 500 files in the first case, more than 300 in the second case.

> 2) what views were shown in the Eclipse IDE? (Navigator, Package Explorer,
> Synchronize etc.)

I'm pretty sure it was the Project Explorer.

> 3) In which one view exactly code format was called (Navigator, Package
> Explorer or something else)?

It was called from the Project Explorer.

> 4) Was there some changesets created where the project resources were
> included?

No. All Mylyn tasks were disabled, so changes felt in the "<Unassigned>" SVN changeset.

> Also is it possible that the time was actually taken by the build process?
> Or is this happened after build process was finished already?

No build process was running. The progress bar shown that changes were applied, the counter of the processed files completed, but after that and before getting the progress bar to 100% it took a lot of time to complete the whole operation. During this period of time, I took some thread dumps and all of them were similar to the one I pasted. Unfortunately, however, I can't say if the bottleneck was the refresh or the SVNChangeSetSorter. 

Next build then started after the whole process finished (i.e.: after the progress bar reached 100% and the modal dialog closed).
Comment 3 Mauro Molinari CLA 2012-11-02 15:54:13 EDT
Another idea: I'm using a 64-bit Windows system. I don't know what's the current situation, but I remember that in the past the 64-bit version of Eclipse didn't use any native implementation of the file system access layer, compared to the 32-bit version. Could this make a difference for such use case?
Comment 4 Alexander Gurov CLA 2012-11-02 16:02:15 EDT
(In reply to comment #2)
So, in the end our cases doesn't seem that different from each other except for the time taken to finish the operation.
In my case the last stage of code formatting was finished very fast.

(In reply to comment #3)
It is possible, probably, but unfortunately I've no way to check it since I don't have a 64 bit Windows system.
Comment 5 Mauro Molinari CLA 2012-11-02 16:34:29 EDT
(In reply to comment #4)
> (In reply to comment #2)
> So, in the end our cases doesn't seem that different from each other except
> for the time taken to finish the operation.
> In my case the last stage of code formatting was finished very fast.

If you try to address the performance issue on SVNChangeSetSorter and push it in the EA build (or in a patched JAR attached here) I may try to see if it solves my problem... As you wish.
Comment 6 Alexander Gurov CLA 2012-11-03 07:54:42 EDT
I've found some useless code that could issue additional refreshes in the SVNChangeSetContentProvider and removed it. Also there was a way to group and reduce redrawing of change sets viewer.
SVNChangeSetSorter also was cleaned in regards to excessive work it performed while working (but it shouldn't have affected your work unless you have hundreds or more of incoming change sets in the Synchronize View).
For now I'll mark the task as resolved/fixed since all the changes are directly related to the described problem and as for me it now works faster.
If the problem will still appear then please reopen the report and I'll try looking further into it.