This Bugzilla instance is a read-only archive of historic NetBeans bug reports. To report a bug in NetBeans please follow the project's instructions for reporting issues.

Bug 239165 - org.netbeans.core.output2.OutputDocument.stateChanged: LowPerformance took 161903 ms.
Summary: org.netbeans.core.output2.OutputDocument.stateChanged: LowPerformance took 16...
Status: RESOLVED WORKSFORME
Alias: None
Product: platform
Classification: Unclassified
Component: Output Window (show other bugs)
Version: 8.0
Hardware: All All
: P3 normal (vote)
Assignee: Jaroslav Havlin
URL:
Keywords: PERFORMANCE
Depends on:
Blocks:
 
Reported: 2013-12-05 16:33 UTC by Jesse Glick
Modified: 2013-12-09 09:42 UTC (History)
1 user (show)

See Also:
Issue Type: DEFECT
Exception Reporter: 205813


Attachments
nps snapshot (368.33 KB, application/nps)
2013-12-05 16:33 UTC, Jesse Glick
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Jesse Glick 2013-12-05 16:33:47 UTC
This issue was reported manually by jglick.
It already has 1 duplicates 


Build: NetBeans IDE Dev (Build 20131204-1205f74381c7)
VM: Java HotSpot(TM) Client VM, 24.45-b08, Java(TM) SE Runtime Environment, 1.7.0_45-b18
OS: Linux

User Comments:
jglick: IDE hung after killing a Maven Surefire test. Had to use https://github.com/jglick/jkillthread to kill "Maven ComandLine Output Redirection", at which point it recovered.

"exec_Test (?Test)_29" prio=10 tid=0x4f5d9400 nid=0x602a in Object.wait() [0x55ff0000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	at java.lang.Object.wait(Object.java:503)
	at org.openide.util.Task.waitFinished(Task.java:135)
	- locked <0x938457e8> (a org.openide.util.RequestProcessor$Task)
	at org.openide.util.RequestProcessor$Task.waitFinished(RequestProcessor.java:1677)
	at org.netbeans.modules.maven.execute.CommandLineOutputHandler.waitFor(CommandLineOutputHandler.java:189)
	at org.netbeans.modules.maven.execute.MavenCommandLineExecutor.run(MavenCommandLineExecutor.java:227)
	at org.netbeans.core.execution.RunClassThread.run(RunClassThread.java:153)
"Maven ComandLine Output Redirection" daemon prio=10 tid=0x5a3f0400 nid=0x5e9b runnable [0x550fe000]
   java.lan



Maximum slowness yet reported was 161903 ms, average is 161903
Comment 1 Jesse Glick 2013-12-05 16:33:52 UTC
Created attachment 142872 [details]
nps snapshot
Comment 2 Jesse Glick 2013-12-05 17:07:14 UTC
The relevant part of the livelock:

"Maven ComandLine Output Redirection" daemon prio=10 tid=0x5a3f0400 nid=0x5e9b runnable [0x550fe000]
   java.lang.Thread.State: RUNNABLE
	at sun.misc.Unsafe.putChar(Native Method)
	at java.nio.DirectCharBufferS.put(DirectCharBufferS.java:291)
	at org.netbeans.core.output2.OutWriter.doWrite(OutWriter.java:483)
	- locked <0x93845ab8> (a org.netbeans.core.output2.OutWriter)
	at org.netbeans.core.output2.OutWriter.print(OutWriter.java:569)
	- locked <0x93845ab8> (a org.netbeans.core.output2.OutWriter)
	at org.netbeans.core.output2.OutWriter.printANSI(OutWriter.java:619)
	at org.netbeans.core.output2.OutWriter.doWrite(OutWriter.java:420)
	- locked <0x93845ab8> (a org.netbeans.core.output2.OutWriter)
	at org.netbeans.core.output2.OutWriter.write(OutWriter.java:542)
	- locked <0x93845ab8> (a org.netbeans.core.output2.OutWriter)
	at java.io.PrintWriter.write(PrintWriter.java:456)
	- locked <0x93845ab8> (a org.netbeans.core.output2.OutWriter)
	at java.io.PrintWriter.write(PrintWriter.java:473)
	at java.io.PrintWriter.print(PrintWriter.java:603)
	at org.netbeans.modules.maven.execute.CommandLineOutputHandler$Output.run(CommandLineOutputHandler.java:291)
	at org.openide.util.RequestProcessor$Task.run(RequestProcessor.java:1423)
	at org.openide.util.RequestProcessor$Processor.run(RequestProcessor.java:2033)
"AWT-EventQueue-0" prio=10 tid=0x57e60000 nid=0x2965 waiting for monitor entry [0x56bf6000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at org.netbeans.core.output2.AbstractLines.getLineCount(AbstractLines.java:435)
	- waiting to lock <0x93845ab8> (a org.netbeans.core.output2.OutWriter)
	at org.netbeans.core.output2.OutputDocument.stateChanged(OutputDocument.java:469)
	at org.netbeans.core.output2.AbstractLines.run(AbstractLines.java:280)
	at org.openide.util.Mutex.doEvent(Mutex.java:1348)
	at org.openide.util.Mutex.readAccess(Mutex.java:355)
	at org.netbeans.core.output2.AbstractLines.fire(AbstractLines.java:274)
	at org.netbeans.core.output2.AbstractLines.actionPerformed(AbstractLines.java:247)
	at javax.swing.Timer.fireActionPerformed(Timer.java:312)
	at javax.swing.Timer$DoPostEvent.run(Timer.java:244)
	at java.awt.event.InvocationEvent.dispatch(InvocationEvent.java:251)
	at java.awt.EventQueue.dispatchEventImpl(EventQueue.java:733)
	at java.awt.EventQueue.access$200(EventQueue.java:103)
	at java.awt.EventQueue$3.run(EventQueue.java:694)
	at java.awt.EventQueue$3.run(EventQueue.java:692)
	at java.security.AccessController.doPrivileged(Native Method)
	at java.security.ProtectionDomain$1.doIntersectionPrivilege(ProtectionDomain.java:76)
	at java.awt.EventQueue.dispatchEvent(EventQueue.java:703)
	at org.netbeans.core.TimableEventQueue.dispatchEvent(TimableEventQueue.java:159)
	at java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:242)
	at java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:161)
	at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:150)
	at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:146)
	at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:138)
	at java.awt.EventDispatchThread.run(EventDispatchThread.java:91)

Happened when configuring Surefire to display live output (normally I have that disabled).
Comment 3 Jesse Glick 2013-12-05 17:09:04 UTC
(Seemed reproducible in that context, by the way: running jenkinsci/jenkins/test/src/test/java/hudson/cli/GroovyshCommandTest.java after editing its pom.xml to say <redirectTestOutputToFile>false</redirectTestOutputToFile>.)
Comment 4 Jaroslav Havlin 2013-12-06 15:45:11 UTC
> User Comments:
> jglick: IDE hung after killing a Maven Surefire test.
Did you use the "Stop" button in Output window, or some external command.

(In reply to Jesse Glick from comment #3)
> (Seemed reproducible in that context, by the way: running
> jenkinsci/jenkins/test/src/test/java/hudson/cli/GroovyshCommandTest.java
Can you reproduce the bug every time you run the test with live output
(redirectTestOutputToFile=false)? I haven't been able to reproduce it yet.

Thank you.
Comment 5 Jesse Glick 2013-12-06 17:13:49 UTC
(In reply to Jaroslav Havlin from comment #4)
> Did you use the "Stop" button in Output window, or some external command.

Killed the process from a shell (IIRC).

> Can you reproduce the bug every time you run the test with live output?

Sorry, forgot that you would also need to delete

    quit\n

from the end of the test input, so that the test keeps running rather than passing and exiting on its own.

At any rate, I am no longer able to reproduce it (at least in 20131206-3422eed6fdbf). Perhaps the trigger condition involved some other edited sources which have since been further updated.
Comment 6 Jaroslav Havlin 2013-12-09 09:42:12 UTC
(In reply to Jesse Glick from comment #5)
> Sorry, forgot that you would also need to delete
>     quit\n
OK

> At any rate, I am no longer able to reproduce it (at least in
> 20131206-3422eed6fdbf). Perhaps the trigger condition involved some other
> edited sources which have since been further updated.
I cannot reproduce it with today's build, too.
Hopefully I can close the issue for now. Please reopen it if you encounter the bug again.
Thank you very much, Jesse.