Bug 63620

Summary: jmeter GUI hangs when viewing Big JSON body with no space
Product: JMeter Reporter: Frederic Girard <youri.andropov>
Component: HTTPAssignee: JMeter issues mailing list <issues>
Status: NEW ---    
Severity: major CC: p.mouawad
Priority: P2    
Version: 5.1.1   
Target Milestone: ---   
Hardware: PC   
OS: All   
Attachments: thread dumps & GC logs
thread dump

Description Frederic Girard 2019-07-30 08:21:01 UTC
Hello, while doing a simple HTTP test, I notice that jmeter GUI freezes everytimes.
Jmeter log shows that the test finishes normally, no error reported, but the GUI is frozen.

One of these requests' responses is huge (~7 MB), i think that's the reason of the freeze. I thought it was caused by the "result tree view", but the GUI hangs even if this listener is disabled.

When I enable the "save response as MD5 hash", the GUI does not hang, but I can no more use response assertions...

FYI, I'm working in GUI mode only while creating/debugging scripts, and I work with a 768 MB heap.

Is there any way to prevent this freeze ?
Comment 1 Philippe Mouawad 2019-07-30 20:17:00 UTC
(In reply to Frederic Girard from comment #0)
> Hello, while doing a simple HTTP test, I notice that jmeter GUI freezes
> everytimes.
> Jmeter log shows that the test finishes normally, no error reported, but the
> GUI is frozen.
> 
> One of these requests' responses is huge (~7 MB), i think that's the reason
> of the freeze. I thought it was caused by the "result tree view", but the
> GUI hangs even if this listener is disabled.
> 
> When I enable the "save response as MD5 hash", the GUI does not hang, but I
> can no more use response assertions...
> 
> FYI, I'm working in GUI mode only while creating/debugging scripts, and I
> work with a 768 MB heap.
> 
> Is there any way to prevent this freeze ?

Hello,
1/ When does the freeze happen exactly ?
2/ Could you provide the response of 7MB, or confirm what it contains does not contain spaces ? Is it textual ?
3/ When it freezes can you try doing 3 consecutive thread dumps at 5s interval (use jstack) ?
4/ Could you enable verbose gc by removing rem from line 154 of jmeter.bat :

rem set VERBOSE_GC=-verbose:gc -Xloggc:gc_jmeter_%%p.log -XX:+PrintGCDetails -XX:+PrintGCCause -XX:+PrintTenuringDistribution -XX:+PrintHeapAtGC -XX:+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCDateStamps -XX:+PrintAdaptiveSizePolicy 
and provide gc_jmeter_XXX.log generated ?

Thank you
Comment 2 Frederic Girard 2019-07-31 08:30:48 UTC
Created attachment 36691 [details]
thread dumps & GC logs
Comment 3 Frederic Girard 2019-07-31 08:36:39 UTC
Philippe,

1) jmeter freezes as soon as the huge response is received

2) Not sure I can provide the full response. It is full text (JSON), and contains many spaces (63336).

3&4) Please see attached file. Note that I usually use IBM J9 SDK, but here I made the thread dumps with the Oracle HotSpot. Same problem happens.

GC seems frenetic when the response is received. Not sure G1 GC is appropriate with such big objects : humongous allocations are costly. Maybe CMS is better.
Nevertheless, with IBM J9 and gencon strategy, the problem is the same.

Regards.
Comment 4 Vladimir Sitnikov 2019-07-31 08:43:23 UTC
It looks like the problem is caused by long log entry.

Frederic, can you please check if `jmeter.log` contains very long lines?


I think JMeter should truncate lines it shows in LoggerPanel.
As of now, the only limit there is "show only 1000 latest messages",
however each message might be big, so it might take time to display 1000 of those.

If we limit individual messages with something like "1000 chars maximum", then it would be much more responsive.

Note: even if we improve LoggerPanel, the logging of those long messages itself take time anyway, so it would be nice to know what is the source of the messages.


Relevant stacktrace is:
"AWT-EventQueue-0" #20 prio=6 os_prio=0 tid=0x000000001b073800 nid=0xe04 waiting on condition [0x000000001c40d000]
   java.lang.Thread.State: RUNNABLE
        at org.fife.ui.rsyntaxtextarea.DefaultTokenFactory.augmentTokenList(DefaultTokenFactory.java:77)
        at org.fife.ui.rsyntaxtextarea.DefaultTokenFactory.createToken(DefaultTokenFactory.java:126)
        at org.fife.ui.rsyntaxtextarea.TokenMakerBase.addToken(TokenMakerBase.java:134)
        at org.fife.ui.rsyntaxtextarea.modes.PlainTextTokenMaker.addToken(PlainTextTokenMaker.java:268)
        at org.fife.ui.rsyntaxtextarea.modes.PlainTextTokenMaker.yylex(PlainTextTokenMaker.java:625)
        at org.fife.ui.rsyntaxtextarea.modes.PlainTextTokenMaker.getTokenList(PlainTextTokenMaker.java:338)
        at org.fife.ui.rsyntaxtextarea.RSyntaxDocument.getTokenListForLine(RSyntaxDocument.java:431)
        at org.fife.ui.rsyntaxtextarea.SyntaxView.getLineWidth(SyntaxView.java:306)
        at org.fife.ui.rsyntaxtextarea.SyntaxView.possiblyUpdateLongLine(SyntaxView.java:784)
        at org.fife.ui.rsyntaxtextarea.SyntaxView.updateDamage(SyntaxView.java:836)
        at org.fife.ui.rsyntaxtextarea.SyntaxView.insertUpdate(SyntaxView.java:490)
        at javax.swing.plaf.basic.BasicTextUI$RootView.insertUpdate(BasicTextUI.java:1610)
        at javax.swing.plaf.basic.BasicTextUI$UpdateHandler.insertUpdate(BasicTextUI.java:1869)
        at javax.swing.text.AbstractDocument.fireInsertUpdate(AbstractDocument.java:201)
        at org.fife.ui.rsyntaxtextarea.RSyntaxDocument.fireInsertUpdate(RSyntaxDocument.java:187)
        at javax.swing.text.AbstractDocument.handleInsertString(AbstractDocument.java:748)
        at javax.swing.text.AbstractDocument.insertString(AbstractDocument.java:707)
        at javax.swing.text.PlainDocument.insertString(PlainDocument.java:130)
        at javax.swing.text.AbstractDocument.replace(AbstractDocument.java:669)
        at javax.swing.text.JTextComponent.setText(JTextComponent.java:1669)
        at org.apache.jmeter.gui.LoggerPanel.updateLogEntries(LoggerPanel.java:148)
        - locked <0x00000000d0e2d7a8> (a org.apache.jmeter.gui.util.JSyntaxTextArea)
        at org.apache.jmeter.gui.LoggerPanel.lambda$initWorker$0(LoggerPanel.java:130)
        at org.apache.jmeter.gui.LoggerPanel$$Lambda$57/1973093841.actionPerformed(Unknown Source)
        at javax.swing.Timer.fireActionPerformed(Timer.java:313)
Comment 5 Frederic Girard 2019-07-31 08:54:52 UTC
Hello Vladimir,

Yes it does. As I can't rely on the tree view listener, I'm logging the full response into jmeter log. This response is 7 496 223 bytes long.

I have a JSR223 post processor with : log.info "Response=" + new String(prev.getResponseData())

When I disable this loggging, jmeter GUI does not freeze but as soon as I try to check the response in the result tree view, the GUI freezes.
Comment 6 Vladimir Sitnikov 2019-07-31 09:22:59 UTC
>When I disable this loggging, jmeter GUI does not freeze but as soon as I try to check the response in the result tree view, the GUI freezes.

Please comment the logging statement, make GUI freeze and capture a new thread dump
Comment 7 Frederic Girard 2019-07-31 09:50:21 UTC
Created attachment 36692 [details]
thread dump
Comment 8 Frederic Girard 2019-07-31 09:50:35 UTC
Done.
Comment 9 Felix Schumacher 2019-07-31 10:57:20 UTC
Are there newlines in the JSON data or only normal spaces and tabs? If I remember correctly, rsyntaxtextarea is really problematic on data that has looong lines.

You might get away by pretty printing your JSON data in a post processor or by extracting parts of the JSON data.
Comment 10 Vladimir Sitnikov 2019-07-31 11:05:53 UTC
Felix, as you see, it is not "just rsyntaxtextarea"

ViewResultsInTree suffers as well:


"AWT-EventQueue-0" #20 prio=6 os_prio=0 tid=0x000000001b126800 nid=0x13c0 runnable [0x000000001c33c000]
   java.lang.Thread.State: RUNNABLE
        at javax.swing.text.GapContent.getChars(GapContent.java:213)
        at javax.swing.text.AbstractDocument.getText(AbstractDocument.java:810)
        at javax.swing.text.WrappedPlainView.loadText(WrappedPlainView.java:309)
        at javax.swing.text.WrappedPlainView.calculateBreakPosition(WrappedPlainView.java:235)
        at javax.swing.text.WrappedPlainView$WrappedLine.breakLines(WrappedPlainView.java:782)
        at javax.swing.text.WrappedPlainView$WrappedLine.getPreferredSpan(WrappedPlainView.java:561)
        at javax.swing.text.View.getMinimumSpan(View.java:250)
        at javax.swing.text.BoxView.calculateMajorAxisRequirements(BoxView.java:871)
        at javax.swing.text.BoxView.checkRequests(BoxView.java:930)
        at javax.swing.text.BoxView.setSpanOnAxis(BoxView.java:329)
        at javax.swing.text.BoxView.layout(BoxView.java:709)
        at javax.swing.text.BoxView.setSize(BoxView.java:397)
        at javax.swing.text.WrappedPlainView.setSize(WrappedPlainView.java:388)
        at javax.swing.plaf.basic.BasicTextUI$RootView.setSize(BasicTextUI.java:1722)
        at javax.swing.plaf.basic.BasicTextUI.getPreferredSize(BasicTextUI.java:912)
        at javax.swing.JComponent.getPreferredSize(JComponent.java:1662)
        at javax.swing.JEditorPane.getPreferredSize(JEditorPane.java:1333)
        at javax.swing.JViewport.getViewSize(JViewport.java:999)
        at javax.swing.plaf.basic.BasicScrollPaneUI.syncScrollPaneWithViewport(BasicScrollPaneUI.java:278)
        at javax.swing.plaf.basic.BasicScrollPaneUI$Handler.stateChanged(BasicScrollPaneUI.java:1034)
        at javax.swing.JViewport.fireStateChanged(JViewport.java:1369)
        at javax.swing.JViewport.setView(JViewport.java:969)
        at javax.swing.JScrollPane.setViewportView(JScrollPane.java:1007)
        at org.apache.jmeter.visualizers.RenderAsText.showTextResponse(RenderAsText.java:38)
        at org.apache.jmeter.visualizers.RenderAsText.renderResult(RenderAsText.java:31)
        at org.apache.jmeter.visualizers.ViewResultsFullVisualizer.valueChanged(ViewResultsFullVisualizer.java:392)
        at org.apache.jmeter.visualizers.ViewResultsFullVisualizer.valueChanged(ViewResultsFullVisualizer.java:365)
        at javax.swing.JTree.fireValueChanged(JTree.java:2934)
        at javax.swing.JTree$TreeSelectionRedirector.valueChanged(JTree.java:3398)
        at javax.swing.tree.DefaultTreeSelectionModel.fireValueChanged(DefaultTreeSelectionModel.java:635)
        at javax.swing.tree.DefaultTreeSelectionModel.notifyPathChange(DefaultTreeSelectionModel.java:1093)
        at javax.swing.tree.DefaultTreeSelectionModel.setSelectionPaths(DefaultTreeSelectionModel.java:294)
        at javax.swing.tree.DefaultTreeSelectionModel.setSelectionPath(DefaultTreeSelectionModel.java:188)
        at javax.swing.JTree.setSelectionPath(JTree.java:1641)
        at javax.swing.plaf.basic.BasicTreeUI.selectPathForEvent(BasicTreeUI.java:2393)
        at javax.swing.plaf.basic.BasicTreeUI$Handler.handleSelection(BasicTreeUI.java:3609)
        at javax.swing.plaf.basic.BasicTreeUI$Handler.mousePressed(BasicTreeUI.java:3548)
        at java.awt.Component.processMouseEvent(Component.java:6536)
Comment 11 Frederic Girard 2019-07-31 11:16:21 UTC
The response is a linearized (single line) JSON with no carriage return, no indenting spaces or tabs.
Comment 12 Felix Schumacher 2019-07-31 12:42:33 UTC
(In reply to Vladimir Sitnikov from comment #10)
> Felix, as you see, it is not "just rsyntaxtextarea"
> 
> ViewResultsInTree suffers as well:

Right, but it is in the calculation of the width of lines to break them apart, so it would still be helpful to try to pretty print the large json structure (if it shortens the lines), don't you think?

> 
> 
> "AWT-EventQueue-0" #20 prio=6 os_prio=0 tid=0x000000001b126800 nid=0x13c0
> runnable [0x000000001c33c000]
>    java.lang.Thread.State: RUNNABLE
>         at javax.swing.text.GapContent.getChars(GapContent.java:213)
>         at
> javax.swing.text.AbstractDocument.getText(AbstractDocument.java:810)
>         at
> javax.swing.text.WrappedPlainView.loadText(WrappedPlainView.java:309)
>         at
> javax.swing.text.WrappedPlainView.calculateBreakPosition(WrappedPlainView.
> java:235)
>         at
> javax.swing.text.WrappedPlainView$WrappedLine.breakLines(WrappedPlainView.
> java:782)
>
Comment 13 Vladimir Sitnikov 2019-07-31 13:00:37 UTC
> Right, but it is in the calculation of the width of lines to break them apart, so it would still be helpful to try to pretty print the large json structure (if it shortens the lines), don't you think?

1) An option to pretty-print based on the content type makes sense. However it might "defeat" regular expressions because "user-visible" json would be different from the one that came from the network.
However I do support the idea of pretty-printing by default

2) Even though we have content type, it is not always right. For instance, they might sent the data as text/plain, and we have very little clue on how to pretty-print.

3) We might want to implement an option to "forcibly add newlines" for lines exceeding N characters. A plus would be to put that newlines in-between word breaks so it won't tear words. That might be a decent workaround.

4) It might be a Java-related issue. For instance, they say https://bugs.openjdk.java.net/browse/JDK-4202291 is fixed in Java 6
So it might be JMeter code is doing something wrong. We might want to analyze what is causing that slowness.
For instance, what if we limit "the maximum width" of the textview? Would it influence text wrapping algorithm?
Comment 14 Felix Schumacher 2019-07-31 13:30:42 UTC
(In reply to Vladimir Sitnikov from comment #13)
> > Right, but it is in the calculation of the width of lines to break them apart, so it would still be helpful to try to pretty print the large json structure (if it shortens the lines), don't you think?
> 
> 1) An option to pretty-print based on the content type makes sense. However
> it might "defeat" regular expressions because "user-visible" json would be
> different from the one that came from the network.
> However I do support the idea of pretty-printing by default

I didn't think about pretty printing by us, but by the user (at least in this case), but we could think about it.

> 
> 2) Even though we have content type, it is not always right. For instance,
> they might sent the data as text/plain, and we have very little clue on how
> to pretty-print.

right. No idea here, we could try to guess the content, but I am pretty sure this would be a bad idea.

> 
> 3) We might want to implement an option to "forcibly add newlines" for lines
> exceeding N characters. A plus would be to put that newlines in-between word
> breaks so it won't tear words. That might be a decent workaround.

As kind of a fallback pretty printer? That could work (with the addition of soft and hard breaks in the case there are no word boundaries)

> 
> 4) It might be a Java-related issue. For instance, they say
> https://bugs.openjdk.java.net/browse/JDK-4202291 is fixed in Java 6
> So it might be JMeter code is doing something wrong. We might want to
> analyze what is causing that slowness.
> For instance, what if we limit "the maximum width" of the textview? Would it
> influence text wrapping algorithm?

Or the fix has not been implemented or re-surfaced? There is mentioned that adding a newline to the text would be a workaround.

@Frederic could you try to add a newline at the end of your data?
Comment 15 Vladimir Sitnikov 2019-07-31 13:35:14 UTC
> I didn't think about pretty printing by us, but by the user 

Note: pretty printing takes time in production systems, so JMeter can't enforce everybody to pretty-print their data.
JavaScript is often minified, and the issue would be very same there.

> As kind of a fallback pretty printer?

Exactly. It seems to be not that hard to implement, and it would probably solve UI freezes.
Comment 16 Frederic Girard 2019-07-31 13:54:51 UTC
I'm sure it wouldn't be a good idea to force the pretty print of HTTP responses, because the response report wouldn't be reliable (think about response assertions).

>> @Frederic could you try to add a newline at the end of your data?

Could you please be more specific ? I don't understand what you mean.
Do you want me to add a  " + '\r\n' " at the end of my log.info ?
Or do you want me to alter the SampleResult ?
Comment 17 Felix Schumacher 2019-07-31 14:20:18 UTC
(In reply to Frederic Girard from comment #16)
> I'm sure it wouldn't be a good idea to force the pretty print of HTTP
> responses, because the response report wouldn't be reliable (think about
> response assertions).
> 
> >> @Frederic could you try to add a newline at the end of your data?
> 
> Could you please be more specific ? I don't understand what you mean.
> Do you want me to add a  " + '\r\n' " at the end of my log.info ?
> Or do you want me to alter the SampleResult ?

I would like you to try two things. First add the new line to the log.info and second try to re-format the data in a post processor and see, if it helps when you have the view results tree enabled again.
Comment 18 Frederic Girard 2019-08-01 08:26:03 UTC
Hello,

I did both tests.
1) addind a carriage return in the log.info had no effect.
2) I'm using JsonOutput to prettyPrint the json response, and jmeter does not freeze, until I click on the sample in the result tree view. The output is 269246 lines long in jmeter log.
Comment 19 davelee 2021-07-09 02:16:12 UTC
Is there any solution to this problem?

In my case, the screen freezes even if json is pretty(json format).

Because my test is a 400kb value encoded base64 in the data.

base54 data is single line.

Please help me.