Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Inserting some characters in JTextPane causes performance problems and memory leak

My chat client has a JTextPane in which text is inserted, which can be up to a few lines per second. It usually works fine, even for a longer period of time (e.g. an hour), however sometimes it just gets incredibly slow, using a lot of CPU and memory, sometimes up to 1GB and practically freezing completely.

I added the "-Xrunhprof:heap=sites" parameter to find out what was using the memory and from what I could gather, it has something to do with text rendering, although I don't really know about this stuff, so it's more an educated guess. This is part of the result, taken while the memory usage was unusually high. I included the appropriate trace under each entry. Other heap dumps looked slightly different, but it always pointed to the same or similar classes (something with Glyph in the name). Not sure how to properly interpret this and if it is really helpful for solving this problem.

         percent          live          alloc'ed  stack class
rank   self  accum     bytes objs     bytes  objs trace name
   1 16.33% 16.33%  11209120 350285  99416352 3106761 319103 java.awt.geom.Rectangle2D$Float

TRACE 319103:
java.awt.geom.RectangularShape.<init>(RectangularShape.java:56)
java.awt.geom.Rectangle2D.<init>(Rectangle2D.java:511)
java.awt.geom.Rectangle2D$Float.<init>(Rectangle2D.java:111)
sun.font.StandardGlyphVector$GlyphStrike.getGlyphOutlineBounds(StandardGlyphVector.java:1790)

   2 14.28% 30.61%   9799744 3958  52026864 49485 319095 float[]

TRACE 319095:
sun.font.StandardGlyphVector.getGlyphInfo(StandardGlyphVector.java:851)
sun.font.ExtendedTextSourceLabel.createCharinfo(ExtendedTextSourceLabel.java:583)
sun.font.ExtendedTextSourceLabel.getCharinfo(ExtendedTextSourceLabel.java:509)
sun.font.ExtendedTextSourceLabel.getLineBreakIndex(ExtendedTextSourceLabel.java:455)

   3  8.17% 38.77%   5604560 350285  49708176 3106761 319110 sun.font.DelegatingShape

TRACE 319110:
sun.font.DelegatingShape.<init>(DelegatingShape.java:43)
sun.font.StandardGlyphVector.getGlyphVisualBounds(StandardGlyphVector.java:586)
sun.font.StandardGlyphVector.getGlyphInfo(StandardGlyphVector.java:864)
sun.font.ExtendedTextSourceLabel.createCharinfo(ExtendedTextSourceLabel.java:583)

   4  7.96% 46.74%   5466576 9933  40683104 164341 319090 float[]

TRACE 319090:
sun.font.GlyphLayout$GVData.createGlyphVector(GlyphLayout.java:596)
sun.font.GlyphLayout.layout(GlyphLayout.java:476)
sun.font.ExtendedTextSourceLabel.createGV(ExtendedTextSourceLabel.java:325)
sun.font.ExtendedTextSourceLabel.getGV(ExtendedTextSourceLabel.java:311)

   5  4.07% 50.81%   2795304 9933  21434888 164341 319089 int[]

TRACE 319089:
sun.font.GlyphLayout$GVData.createGlyphVector(GlyphLayout.java:591)
sun.font.GlyphLayout.layout(GlyphLayout.java:476)
sun.font.ExtendedTextSourceLabel.createGV(ExtendedTextSourceLabel.java:325)
sun.font.ExtendedTextSourceLabel.getGV(ExtendedTextSourceLabel.java:311)

   6  3.71% 54.52%   2544072 106003 183421728 7642572 319087 java.awt.geom.Point2D$Float

TRACE 319087:
java.awt.geom.Point2D.<init>(Point2D.java:237)
java.awt.geom.Point2D$Float.<init>(Point2D.java:69)
sun.font.FileFontStrike.getGlyphMetrics(FileFontStrike.java:791)
sun.font.FileFontStrike.getGlyphMetrics(FileFontStrike.java:787)

   7  3.70% 58.22%   2539560 105815 182834016 7618084 319088 java.awt.geom.Point2D$Float

TRACE 319088:
java.awt.geom.Point2D.<init>(Point2D.java:237)
java.awt.geom.Point2D$Float.<init>(Point2D.java:69)
sun.font.FileFontStrike.getGlyphMetrics(FileFontStrike.java:809)
sun.font.FileFontStrike.getGlyphMetrics(FileFontStrike.java:787)

   8  2.20% 60.42%   1512888 6109  14728808 123309 319100 java.awt.Shape[]

TRACE 319100:
sun.font.StandardGlyphVector.getGlyphVisualBounds(StandardGlyphVector.java:580)
sun.font.StandardGlyphVector.getGlyphInfo(StandardGlyphVector.java:864)
sun.font.ExtendedTextSourceLabel.createCharinfo(ExtendedTextSourceLabel.java:583)
sun.font.ExtendedTextSourceLabel.getCharinfo(ExtendedTextSourceLabel.java:509)

   9  2.20% 62.62%   1507120 2151  49362432 73824 319503 float[]

TRACE 319503:
sun.font.StandardGlyphVector.getGlyphInfo(StandardGlyphVector.java:851)
sun.font.ExtendedTextSourceLabel.createCharinfo(ExtendedTextSourceLabel.java:583)
sun.font.ExtendedTextSourceLabel.getCharinfo(ExtendedTextSourceLabel.java:509)
sun.font.ExtendedTextSourceLabel.getCharX(ExtendedTextSourceLabel.java:353)

  10  2.09% 64.71%   1437120 44910  99416352 3106761 319111 java.awt.geom.Rectangle2D$Float

TRACE 319111:
java.awt.geom.RectangularShape.<init>(RectangularShape.java:56)
java.awt.geom.Rectangle2D.<init>(Rectangle2D.java:511)
java.awt.geom.Rectangle2D$Float.<init>(Rectangle2D.java:128)
java.awt.geom.Rectangle2D$Float.getBounds2D(Rectangle2D.java:251)

  11  1.84% 66.55%   1262456    6   1707160    18 307780 char[]

TRACE 307780:
javax.swing.text.GapContent.allocateArray(GapContent.java:94)
javax.swing.text.GapVector.resize(GapVector.java:214)
javax.swing.text.GapVector.shiftEnd(GapVector.java:229)
javax.swing.text.GapContent.shiftEnd(GapContent.java:345)

  12  1.16% 67.71%    794640 9933  13147280 164341 319092 sun.font.StandardGlyphVector

TRACE 319092:
    java.awt.font.GlyphVector.<init>(GlyphVector.java:109)
 sun.font.StandardGlyphVector.<init>(StandardGlyphVector.java:185)
    sun.font.GlyphLayout$GVData.createGlyphVector(GlyphLayout.java:607)
    sun.font.GlyphLayout.layout(GlyphLayout.java:476)

I also monitored the program with JConsole and noticed that just when it started using more ressources, there were some characters in the chatlog I didn't recognize (e.g. an emoticon, some sort of Indian character and some sort of Thai character that were used as part of an emoticon). I tried inserting the same characters into the JTextPane myself, which took unusually long itself and also had the effect of making subsequent text insertions a lot slower.

I created an SSCCE with which I could reproduce the problem:

  • After inserting the character that apparently breaks something..
    • ..it gets a lot slower after a few hundred lines if no more linebreaks are inserted.
    • ..it gets a lot slower when changing a Style that has been added to the StyledDocument with every insert, if there are already a few hundred lines present.
    • ..it otherwise gets only slightly slower (a few percent more CPU usage), but gradually uses more and more memory.

I guess not adding a linebreak treats all inserted text as one entity, while changing a Style that has been added to the StyledDocument might update the whole document somehow, although I was not aware of that, since it doesn't actually change the style of already inserted text.

Now here is the SSCCE (tested with jdk1.7.0_21), with a simple command input: "test" adds a number of identical lines, "insert1" or "insert2" adds a character that slows everything down, "style" changes between changing a style that has been added to the StyledDocument and another, "linebreak" toggles between adding linesbreaks and not. Other input is just directly added to the JTextPane.

import java.awt.BorderLayout;
import java.awt.Color;
import java.awt.event.ActionEvent;
import java.awt.event.ActionListener;
import java.util.logging.Level;
import java.util.logging.Logger;
import javax.swing.*;
import javax.swing.text.*;

public class JTextPaneTest extends JFrame implements Runnable, ActionListener {

    JTextPane textPane;
    JTextField input;
    Style styleA;
    SimpleAttributeSet styleB;
    StyledDocument doc;
    boolean setStyleA = false;
    boolean linebreak = true;

    public JTextPaneTest() {
        SwingUtilities.invokeLater(this);
    }

    @Override
    public void run() {

        // Text Pane
        textPane = new JTextPane();
        doc = textPane.getStyledDocument();
        JScrollPane scrollPane = new JScrollPane(textPane);

        // Styles
        styleA = doc.addStyle("styleA", null);
        styleB = new SimpleAttributeSet();

        // Input
        input = new JTextField();
        input.addActionListener(this);

        // Add everything to the window
        this.getContentPane().add(scrollPane, BorderLayout.CENTER);
        getContentPane().add(input, BorderLayout.SOUTH);

        // Prepare and show window
        this.setDefaultCloseOperation(EXIT_ON_CLOSE);
        pack();
        this.setSize(400, 300);
        setVisible(true);
    }

    public static void main(String[] args) {
        new JTextPaneTest();
    }

    void insert(final String text) {
        SwingUtilities.invokeLater(new Runnable() {
            @Override
            public void run() {
                try {
                    if (setStyleA) {
                        // Changing styleA, which is added to the StyledDocument
                        // seems to make the problem worse
                        StyleConstants.setForeground(styleA, Color.blue);
                    }
                    else {
                        StyleConstants.setForeground(styleB, Color.blue);
                    }
                    // Not adding a linebreak seems to make the problem worse
                    String addLinebreak = "";
                    if (linebreak) {
                        addLinebreak = "\n";
                    }
                    doc.insertString(doc.getLength(), text+addLinebreak, null);
                } catch (BadLocationException ex) {
                    Logger.getLogger(JTextPaneTest.class.getName()).log(Level.SEVERE, null, ex);
                }

            }
        });
    }

    @Override
    public void actionPerformed(ActionEvent e) {
        String text = input.getText();

        if (text.equals("test")) {
            new Thread(new Runnable() {
                @Override
                public void run() {
                    // Insert some text to kind of simulate chat messages coming in
                    for (int i = 0; i < 500; i++) {
                        try {
                            Thread.sleep(250);
                        } catch (InterruptedException ex) {
                            Logger.getLogger(JTextPaneTest.class.getName()).log(Level.SEVERE, null, ex);
                        }
                        insert(i + " Test text to sort of simulate a chat message");
                    }
                }
            }).start();
        }
        // Insert text that seems to break something
        // Example 1:
        else if (text.equals("insert1")) {
            insert("\uD83D\uDE3A");
        }
        // Example 2:
        else if (text.equals("insert2")) {
            insert("\u0E07");
        }
        // Toggle changing styleA or styleB
        else if (text.equals("style")) {
            if (this.setStyleA) {
                setStyleA = false;
                insert("Style: B");
            }
            else {
                setStyleA = true;
                insert("Style: A");
            }
        }
        // Toggle printing a linebreak after each insert
        else if (text.equals("linebreak")) {
            if (this.linebreak) {
                linebreak = false;
                insert("Linebreak: OFF");
            }
            else {
                linebreak = true;
                insert("Linebreak: ON");
            }
        }
        // Output entered text
        else {
            insert(input.getText());
            input.setText("");
        }
    } 
}

The question is now, what is happening there. Is it a known bug? Am I doing something wrong? It seems strange that adding a single character would have that effect. Even if it was a little more costly to render, it shouldn't cause that much trouble.

If it is a Java bug, what can I do as a workaround? Maybe filter the affected characters somehow? But I wouln't even know which those are. If I am doing something wrong, what is it? Maybe I have to prepare the text somehow before inserting it? Change it's encoding? Maybe it's something very basic and simple I need to change? Please help. :)

Update: The following picture shows what happens while inserting 5000 lines of text (which takes about 20 minutes), on the left without doing anything special, on the right after inserting one of the troublesome characters. I requested a Garbage Collection in JConsole after it finished and the left one went down to about 10 MB, while the right one only went down to about 45 MB, which is significantly more, taking into account that the only difference is one inserted character. The drop after that is just JConsole disconnecting. You can also see that the CPU usage is about 0.5 percentage points higher on the right. I repeated this test several times, the result was always the same. This is without the linebreak/Style stuff that makes the problem even more visible.

Memory leak

like image 796
user2375667 Avatar asked May 16 '13 02:05

user2375667


1 Answers

Here's what I did:

  1. Run SSCCE program
  2. Attach JVisualVM and begin memory profiler
  3. Let the program initialize and stabilize the heap; force GC and take a snapshot from the profiler.
  4. Input "test" to the program and let it finish adding new content
  5. Force GC from JVisualVM and take a snapshot from the profiler
  6. Input "insert1" and "insert2" to the program to generate the problem characters
  7. Input "test" to the program to generate additional, normal content and let it finish
  8. Force GC from JVisualVM and take snapshot from the profiler, also have JVisualVM generate a heap dump

I see what you mentioned in your question, but would like to add:

  • The special characters DO use a separate rendering path from your normal sample text. Comparing the differences between snapshots (3) and (5), for example, shows only one class from the sun.font.* package. The difference between snapshot (5) and (8) shows an additional ~40 classes are now used. Included in these are the classes you mentioned: sun.font.StandardGlyphVector, sun.font.ExtendedTextSourceLabel, sun.font.StandardTextSource, and sun.font.DelegatingShape.

  • Of the above mentioned classes, most have ~850 live objects, each, in my profiling run. But sun.font.DelegatingShape is an outlier with ~20,000+ live objects.

  • I used JVisualVM to explore the final heap dump and focused on the DelegatingShape class. These objects are holding references to distinct java.awt.geom.Rectangle2D$Float objects. Both of these are kept alive by a Shape[] array inside StandardGlyphVector and shared with ExtendedTextSourceLabel. Each array contained ~49 non-null elements.

  • Looking at the source code, these arrays are held by soft references, as a type of cache for the visual bounding boxes for the individual glyphs (see: StandardGlyphVector.getGlyphVisualBounds()). The good news is that objects reachable only through Soft References can be garbage collected and don't directly constitute a memory leak on their own. The VM will leave them in memory (growing the heap) as long as it can. If the objects are STRONGLY held by some other means then they will never be collected; I don't notice any obvious strong references at this time.

But why so many ExtendedTextSourceLabels? To make a long story short, your JTextPane is implemented on top of javax.swing.text.BoxView which, after inserting ~1002 lines via your document, contains ~4004 ParagraphView child objects. Each view contains its own TextLayoutStrategy and, after traversing a good number of other objects, holds those ExtendedTextSourceLabel instances.

So supporting some subsets of Unicode can be more expensive, both in rendering time and in memory consumption. I have not found any indication of a memory "leak" except for the case that your example keeps the entire history of the "chat conversation" in the styled document of your JTextPane. What can you do?

  • Only show a limited portion of the chat history in the JTextPane, such as only the most recent N entries.

  • Keep the chat history in some other data structure outside of the Swing rendering graph. you'd need to manage the scrolling yourself to "page in" and "page out" portions of the text in/out of the JTextPane, so it only has to render a fraction of the entire history.

EDIT: Profiling run #2

"AWT-EventQueue-0" prio=10 tid=0x00007ff38028c000 nid=0x5f74 runnable [0x00007ff3745db000]
java.lang.Thread.State: RUNNABLE
at javax.swing.text.AbstractDocument$BranchElement.getElementIndex(AbstractDocument.java:2389)
    at javax.swing.text.CompositeView.getViewIndexAtPosition(CompositeView.java:579)
    at javax.swing.text.FlowView$LogicalView.getViewIndexAtPosition(FlowView.java:692)
    at javax.swing.text.CompositeView.getViewIndex(CompositeView.java:497)
    at javax.swing.text.TextLayoutStrategy$AttributedSegment.getAttribute(TextLayoutStrategy.java:520)
    at sun.text.bidi.BidiBase.setPara(BidiBase.java:2711)
    at java.text.Bidi.<init>(Bidi.java:134)
    at java.awt.font.TextMeasurer.initAll(TextMeasurer.java:208)
    at java.awt.font.TextMeasurer.<init>(TextMeasurer.java:167)
    at java.awt.font.LineBreakMeasurer.<init>(LineBreakMeasurer.java:310)

With "linebreaks OFF" performance craters to a dead stop. I took multiple thread dumps and the common point is the LineBreakMeasurer; I picked the trace above because it shows it having to deal with "bidi" (bi-directional) characters.

This doesn't seem to be an issue for me as long as I don't touch the style or linebreak options.

like image 77
William Price Avatar answered Sep 20 '22 17:09

William Price