I connect to MySQL xx.xx.1.20 and do a :
select * from ipligence limit 100000
With Show Text, Grid, Pivot Grid and Client Statistics enabled. In 12.0 it takes 6 seconds to display, while in 14.0 it takes 2m 6s
|
101 KB
|
104 KB
|
125 KB
|
126 KB
|
83 KB
CPU/Memory performance problem with Text pane in 14.0 is a known problem, see issue #8369 for more information.
On my desktop, using your test case, it takes about 7 seconds for 12.0.20-1 to get output displayed, 4 minutes for 14.0.0-alpha-29. I generated some CPU samples using Java VisualVM, the implementation to parse/interpret text is different in editor between 12.0 and 14.0, that makes the difference. See attached screenshots for details:
* ADS 12.0 CPU Summary - this tells you time used to render Text/Grid/Pivot/Stats panes (using ADS 12.0.20-1).
* ADS 12.0 CPU Text Detail - this gives you detail on rendering the Text pane (using ADS 12.0.20-1).
* ADS 14.0 CPU Summary - this tells you time used to render Text/Grid/Pivot/Stats panes (using ADS 14.0.0-alpha-29).
* ADS 14.0 CPU Text Detail - this gives you detail on rendering the Text pane (using ADS 14.0.0-alpha-29).
ADS 12.0.19 is using Vincaed 3.0.5.6
ADS 14.0.0-alpha-28 is using Vincaed 3.0.5.7
ADS 12.0.19 is using Vincaed 3.0.5.6
ADS 14.0.0-alpha-28 is using Vincaed 3.0.5.7
3.0.5.7 introduced a minor fix for the diff view, it should be identical with 3.0.5.6 otherwise. Could you replace the stndeditor/ JARs from 14.0 with the JARs from 12.0 and see if the bug duplicates?
What seems to be happening is that ResultsMimeRegistration.ResultMarkProvider tries to re-compute the error / sql marks for the error stripe (which is on the right side of the editor). In order to do that it searches for the ERROR_TEXT tokens which needs the whole text to be tokenized. Since I assume we have a succession of rapid insertString() calls, we re-parse the same text multiple times.
Some ideas here:
* perhaps SQLResultsSyntax.parseToken got much slower in 14.0 compared to 12.0.
* we could re-compute the text marks with a better approach:
** one way would be to disable the marks recalculation while text is being appended via some Document flag or some other way.
** another way would be to set a timer on the marks recalculation, and delay it for 100-500ms. Then we coalesce multiple calls into a single one.
aquaeditor is not part of aqua-external so I would need access to a fresh version of at least ResultsMimeRegistration in order to work on it.
3.0.5.7 introduced a minor fix for the diff view, it should be identical with 3.0.5.6 otherwise. Could you replace the stndeditor/ JARs from 14.0 with the JARs from 12.0 and see if the bug duplicates?
What seems to be happening is that ResultsMimeRegistration.ResultMarkProvider tries to re-compute the error / sql marks for the error stripe (which is on the right side of the editor). In order to do that it searches for the ERROR_TEXT tokens which needs the whole text to be tokenized. Since I assume we have a succession of rapid insertString() calls, we re-parse the same text multiple times.
Some ideas here:
* perhaps SQLResultsSyntax.parseToken got much slower in 14.0 compared to 12.0.
* we could re-compute the text marks with a better approach:
** one way would be to disable the marks recalculation while text is being appended via some Document flag or some other way.
** another way would be to set a timer on the marks recalculation, and delay it for 100-500ms. Then we coalesce multiple calls into a single one.
aquaeditor is not part of aqua-external so I would need access to a fresh version of at least ResultsMimeRegistration in order to work on it.
ADS 12.0.19 - Vincaed 3.0.5.6 - 10s
ADS 13.0.1-14 - Vincaed 3.0.5.6 - 10s
ADS 14.0.0-dev-10 - Vincaed 3.0.5.6 - 10s
ADS 14.0.0-dev-11 - Vincaed 3.0.5.6 - 10s - 2/14/2013 1:51PM
ADS 14.0.0-dev-12 - Vincaed 3.0.5.6 - 2m 6s - 2/21/2013 11:34AM
ADS 14.0.0-dev-15 - Vincaed 3.0.5.6 - 2m 6s
ADS 14.0.0-dev-20 - Vincaed 3.0.5.6 - 2m 6s
ADS 14.0.0-dev-30 - Vincaed 3.0.5.6 - 2m 6s
ADS 14.0.0-dev-50 - Vincaed 3.0.5.6 - 2m 6s
ADS 14.0.0-alpha-1 - Vincaed 3.0.5.6 - 2m 6s
ADS 14.0.0-alpha-28 - Vincaed 3.0.5.7 - 2m 6s
Problem starts with 14-dev12. SVN changes between dev11 and dev12 are by Fung, Jenny and Kin-Hong. Kin-Hong checked in a change to PivotGrid, while Jenny's changes don't seem to apply. I re-ran the query with all but Text Results enabled in dev12, and it is still slow. So, I think Fung's changes are the cause of the performance problem. Possible SVN changes are ...
31398 | fung | 2/19/2013 10:43:15 PM | Modified | NPE from PaneFactory.closedPane(JEditorPane) The editor pane created in a ResultsetTableView object may not be instantiated by PaneFactory. In this case, PaneFactory.closedPane(editorPane) should not be called upon closing the view. |
31397 | fung | 2/19/2013 9:23:37 PM | Modified | Out of memory error Query Panel: calls ResultsetTableView.clearAndCloseView() to free up memory used by instances of ResultsetTableView |
31396 | fung | 2/19/2013 7:17:54 PM | Modified | NPE from PaneFactory.closedPane(JEditorPane) |
31378 | fung | 2/15/2013 10:08:32 PM | Modified | Table Data Editor: possible memory leaks |
ADS 12.0.19 - Vincaed 3.0.5.6 - 10s
ADS 13.0.1-14 - Vincaed 3.0.5.6 - 10s
ADS 14.0.0-dev-10 - Vincaed 3.0.5.6 - 10s
ADS 14.0.0-dev-11 - Vincaed 3.0.5.6 - 10s - 2/14/2013 1:51PM
ADS 14.0.0-dev-12 - Vincaed 3.0.5.6 - 2m 6s - 2/21/2013 11:34AM
ADS 14.0.0-dev-15 - Vincaed 3.0.5.6 - 2m 6s
ADS 14.0.0-dev-20 - Vincaed 3.0.5.6 - 2m 6s
ADS 14.0.0-dev-30 - Vincaed 3.0.5.6 - 2m 6s
ADS 14.0.0-dev-50 - Vincaed 3.0.5.6 - 2m 6s
ADS 14.0.0-alpha-1 - Vincaed 3.0.5.6 - 2m 6s
ADS 14.0.0-alpha-28 - Vincaed 3.0.5.7 - 2m 6s
Problem starts with 14-dev12. SVN changes between dev11 and dev12 are by Fung, Jenny and Kin-Hong. Kin-Hong checked in a change to PivotGrid, while Jenny's changes don't seem to apply. I re-ran the query with all but Text Results enabled in dev12, and it is still slow. So, I think Fung's changes are the cause of the performance problem. Possible SVN changes are ...
31398 | fung | 2/19/2013 10:43:15 PM | Modified | NPE from PaneFactory.closedPane(JEditorPane) The editor pane created in a ResultsetTableView object may not be instantiated by PaneFactory. In this case, PaneFactory.closedPane(editorPane) should not be called upon closing the view. |
31397 | fung | 2/19/2013 9:23:37 PM | Modified | Out of memory error Query Panel: calls ResultsetTableView.clearAndCloseView() to free up memory used by instances of ResultsetTableView |
31396 | fung | 2/19/2013 7:17:54 PM | Modified | NPE from PaneFactory.closedPane(JEditorPane) |
31378 | fung | 2/15/2013 10:08:32 PM | Modified | Table Data Editor: possible memory leaks |
This problem is caused by the fix, SVN r31396, made for issue #8345. Query panel used to create an editor pane as:
(1) CEditorPane newPane = PaneFactory.createNBEditorPane(SQLResultsKit.MIME_TYPE, true);
(2) Document d = newPane.getEditorKit().createDefaultDocument();
(3) newPane.setDocument(d);
(4) JComponent newWrapper = PaneFactory.getNBEditorWrapComponent(newPane);
(5) Document d = newPane.getEditorKit().createDefaultDocument();
(6) parseQueryResult(d);
(7) newPane.setDocument(d);
SVN r31396
(a) removed (2), (3), (5) and (7),
(b) modified (6) from parseQueryResult(d) to parseQueryResult(newPane.getDocuemnt()).
Sceenshots 'ADS12.0 CPU Text Detail' and 'ADS 14.0 CPU Text Detail' tell us BaseDocument.insertString() method behaves differently in 12.0 and 14.0; does this mean the Document objects created by newPane.getEditorKit().createDefaultDocument() and by editor implicitly have different properties set? and/or different listeners attached?
If I reverted changes made by r31396, of course, the performance problem described in this issue will be gone. However, if I only reverted (2) and (3) so that code above becomes:
(1) CEditorPane newPane = PaneFactory.createNBEditorPane(SQLResultsKit.MIME_TYPE, true);
(2) Document d = newPane.getEditorKit().createDefaultDocument();
(3) newPane.setDocument(d);
(4) JComponent newWrapper = PaneFactory.getNBEditorWrapComponent(newPane);
(6) parseQueryResult(newPane.getDocuemnt());
then, the problem reported by this issue will still show up. Is it possible that (3) and/or (4) is a factor here?
Is there any API that query panel can call to change the behavior of the Document embedded in editor pane? Or something else that query panel can use to work around this problem?
This problem is caused by the fix, SVN r31396, made for issue #8345. Query panel used to create an editor pane as:
(1) CEditorPane newPane = PaneFactory.createNBEditorPane(SQLResultsKit.MIME_TYPE, true);
(2) Document d = newPane.getEditorKit().createDefaultDocument();
(3) newPane.setDocument(d);
(4) JComponent newWrapper = PaneFactory.getNBEditorWrapComponent(newPane);
(5) Document d = newPane.getEditorKit().createDefaultDocument();
(6) parseQueryResult(d);
(7) newPane.setDocument(d);
SVN r31396
(a) removed (2), (3), (5) and (7),
(b) modified (6) from parseQueryResult(d) to parseQueryResult(newPane.getDocuemnt()).
Sceenshots 'ADS12.0 CPU Text Detail' and 'ADS 14.0 CPU Text Detail' tell us BaseDocument.insertString() method behaves differently in 12.0 and 14.0; does this mean the Document objects created by newPane.getEditorKit().createDefaultDocument() and by editor implicitly have different properties set? and/or different listeners attached?
If I reverted changes made by r31396, of course, the performance problem described in this issue will be gone. However, if I only reverted (2) and (3) so that code above becomes:
(1) CEditorPane newPane = PaneFactory.createNBEditorPane(SQLResultsKit.MIME_TYPE, true);
(2) Document d = newPane.getEditorKit().createDefaultDocument();
(3) newPane.setDocument(d);
(4) JComponent newWrapper = PaneFactory.getNBEditorWrapComponent(newPane);
(6) parseQueryResult(newPane.getDocuemnt());
then, the problem reported by this issue will still show up. Is it possible that (3) and/or (4) is a factor here?
Is there any API that query panel can call to change the behavior of the Document embedded in editor pane? Or something else that query panel can use to work around this problem?
I think we could try and optimize the ResultsMimeRegistration.ResultMarkProvider behavior I've talked about.
You could do an experiment and remove "new ResultMarks" from ResultsMimeRegistration.getCustomMimeLookupObjects(). You lose the error stripe marks but I'm curious if speed becomes acceptable.
If this is the bottleneck now, we could replace the calls to refresh() in the ResultMarkProvider document listener with a coalescing timer that has a 500ms delay; we should waste much less CPU and be virtually unnoticeable from an UI standpoint.
I think we could try and optimize the ResultsMimeRegistration.ResultMarkProvider behavior I've talked about.
You could do an experiment and remove "new ResultMarks" from ResultsMimeRegistration.getCustomMimeLookupObjects(). You lose the error stripe marks but I'm curious if speed becomes acceptable.
If this is the bottleneck now, we could replace the calls to refresh() in the ResultMarkProvider document listener with a coalescing timer that has a 500ms delay; we should waste much less CPU and be virtually unnoticeable from an UI standpoint.
If I remove "new ResultMarks" from ResultsMimeRegistration.getCustomMimeLookupObjects() it only takes 6s, so that would seem to fix the problem.
Emilian, can you fix this in the Vincaed editor? or should we do something on our side?
If I remove "new ResultMarks" from ResultsMimeRegistration.getCustomMimeLookupObjects() it only takes 6s, so that would seem to fix the problem.
Emilian, can you fix this in the Vincaed editor? or should we do something on our side?
It must be fixed in ADS, that code is not part of Vincaed. I've emailed you a patch.
It must be fixed in ADS, that code is not part of Vincaed. I've emailed you a patch.
With 14.0.0-beta-76 it takes only 4 seconds to display the result.
With 14.0.0-beta-76 it takes only 4 seconds to display the result.
Issue #9217 |
Closed |
Fixed |
Resolved |
Completion |
No due date |
No fixed build |
No time estimate |
2 issue links |
relates to #8369
Issue #8369Query Analyzer: high memory consumption |
relates to #8345
Issue #8345NPE from PaneFactory.closedPane(JEditorPane) |
CPU/Memory performance problem with Text pane in 14.0 is a known problem, see issue #8369 for more information.
On my desktop, using your test case, it takes about 7 seconds for 12.0.20-1 to get output displayed, 4 minutes for 14.0.0-alpha-29. I generated some CPU samples using Java VisualVM, the implementation to parse/interpret text is different in editor between 12.0 and 14.0, that makes the difference. See attached screenshots for details:
* ADS 12.0 CPU Summary - this tells you time used to render Text/Grid/Pivot/Stats panes (using ADS 12.0.20-1).
* ADS 12.0 CPU Text Detail - this gives you detail on rendering the Text pane (using ADS 12.0.20-1).
* ADS 14.0 CPU Summary - this tells you time used to render Text/Grid/Pivot/Stats panes (using ADS 14.0.0-alpha-29).
* ADS 14.0 CPU Text Detail - this gives you detail on rendering the Text pane (using ADS 14.0.0-alpha-29).