diff --git a/o.n.core/src/org/netbeans/core/Bundle.properties b/o.n.core/src/org/netbeans/core/Bundle.properties --- a/o.n.core/src/org/netbeans/core/Bundle.properties +++ b/o.n.core/src/org/netbeans/core/Bundle.properties @@ -179,3 +179,9 @@ # NbAuthenticatorPanel NbAuthenticatorPanel.userNameLbl.text=&User Name: NbAuthenticatorPanel.passwordLbl.text=&Password: + +# TimableEventQueue +TEQ_LowPerformance=System slowness detected +# {0} time in ms +# {1} time in s +TEQ_BlockedFor=Not reponsive for {0,choice,0#{0} ms|5000#{1} s}. \ No newline at end of file diff --git a/o.n.core/src/org/netbeans/core/TimableEventQueue.java b/o.n.core/src/org/netbeans/core/TimableEventQueue.java --- a/o.n.core/src/org/netbeans/core/TimableEventQueue.java +++ b/o.n.core/src/org/netbeans/core/TimableEventQueue.java @@ -42,15 +42,32 @@ import java.awt.AWTEvent; import java.awt.EventQueue; import java.awt.Toolkit; -import java.util.EmptyStackException; -import java.util.Map; -import java.util.ResourceBundle; +import java.awt.event.ActionEvent; +import java.awt.event.ActionListener; +import java.io.ByteArrayOutputStream; +import java.io.DataOutputStream; +import java.io.IOException; +import java.io.OutputStream; +import java.util.LinkedList; +import java.util.Queue; import java.util.logging.Level; -import java.util.logging.LogRecord; import java.util.logging.Logger; +import javax.swing.Action; import org.netbeans.core.startup.Main; +import org.openide.awt.Notification; +import org.openide.awt.NotificationDisplayer; +import org.openide.filesystems.FileObject; +import org.openide.filesystems.FileUtil; +import org.openide.loaders.DataObject; +import org.openide.nodes.Node; +import org.openide.util.ContextAwareAction; +import org.openide.util.Exceptions; +import org.openide.util.ImageUtilities; import org.openide.util.Mutex; +import org.openide.util.NbBundle; import org.openide.util.RequestProcessor; +import org.openide.util.lookup.Lookups; +import org.openide.windows.WindowManager; /** * Logging event queue that can report problems about too long execution times @@ -62,19 +79,20 @@ implements Runnable { private static final Logger LOG = Logger.getLogger(TimableEventQueue.class.getName()); private static final RequestProcessor RP = new RequestProcessor("Timeable Event Queue Watch Dog", 1, true); // NOI18N - private static final int QUANTUM = Integer.getInteger("org.netbeans.core.TimeableEventQueue.quantum", 5000); // NOI18N - private static final int PAUSE = Integer.getInteger("org.netbeans.core.TimeableEventQueue.pause", 60000); // NOI18N + private static final int QUANTUM = Integer.getInteger("org.netbeans.core.TimeableEventQueue.quantum", 100); // NOI18N + private static final int REPORT = Integer.getInteger("org.netbeans.core.TimeableEventQueue.report", 1000); // NOI18N + private static final int PAUSE = Integer.getInteger("org.netbeans.core.TimeableEventQueue.pause", 15000); // NOI18N - private final RequestProcessor.Task TIMEOUT; - private volatile Map stack; private volatile long ignoreTill; private volatile long start; - + private volatile ActionListener stoppable; + private final Queue pending; public TimableEventQueue() { TIMEOUT = RP.create(this); TIMEOUT.setPriority(Thread.MIN_PRIORITY); + pending = new LinkedList(); } static void initialize() { @@ -97,74 +115,86 @@ e.printStackTrace(); } } + @Override protected void dispatchEvent(AWTEvent event) { try { - tick(); + tick("dispatchEvent"); // NOI18N super.dispatchEvent(event); } finally { done(); } } - @Override - public void postEvent(AWTEvent theEvent) { - try { - tick(); - super.postEvent(theEvent); - } finally { - done(); - } - } - - @Override - public synchronized void push(EventQueue newEventQueue) { - try { - tick(); - super.push(newEventQueue); - } finally { - done(); - } - } - private void done() { - stack = null; TIMEOUT.cancel(); long time = System.currentTimeMillis() - start; - if (time > 50) { - LOG.log(Level.FINE, "done, timer stopped, took {0}", time); + if (time > QUANTUM) { + LOG.log(Level.FINE, "done, timer stopped, took {0}", time); // NOI18N + if (time > REPORT) { + LOG.log(Level.WARNING, "too much time in AWT thread {0}", stoppable); // NOI18N + ActionListener ss = stoppable; + if (ss != null) { + try { + ByteArrayOutputStream out = new ByteArrayOutputStream(); + DataOutputStream dos = new DataOutputStream(out); + ss.actionPerformed(new ActionEvent(dos, 0, "write")); // NOI18N + dos.close(); + pending.add(new NotifySnapshot(out.toByteArray(), time)); + if (pending.size() > 5) { + pending.remove().clear(); + } + stoppable = null; + } catch (Exception ex) { + Exceptions.printStackTrace(ex); + } + ignoreTill = System.currentTimeMillis() + PAUSE; + } + } } else { LOG.log(Level.FINEST, "done, timer stopped, took {0}", time); } + ActionListener ss = stoppable; + if (ss != null) { + ss.actionPerformed(new ActionEvent(this, 0, "cancel")); // NOI18N + stoppable = null; + } + return; } - private void tick() { - stack = null; + private void tick(String name) { start = System.currentTimeMillis(); - if (start >= ignoreTill) { - LOG.log(Level.FINEST, "tick, schedule a timer at {0}", start); + if (start >= ignoreTill && WindowManager.getDefault().getMainWindow().isShowing()) { + LOG.log(Level.FINEST, "tick, schedule a timer for {0}", name); TIMEOUT.schedule(QUANTUM); } } public void run() { - stack = Thread.getAllStackTraces(); - LOG.log(Level.FINER, "timer running"); - for (int i = 0; i < 10; i++) { - if (Thread.interrupted()) { - LOG.log(Level.FINER, "timer cancelled"); - return; - } - Thread.yield(); - System.gc(); - System.runFinalization(); - } - final Map myStack = stack; - if (myStack == null) { - LOG.log(Level.FINER, "timer cancelled"); + if (stoppable != null) { + LOG.log(Level.WARNING, "Still previous controller {0}", stoppable); return; } - + Runnable selfSampler = (Runnable)createSelfSampler(); + if (selfSampler != null) { + selfSampler.run(); + stoppable = (ActionListener)selfSampler; + } + } + + private static Object createSelfSampler() { + FileObject fo = FileUtil.getConfigFile("Actions/Profile/org-netbeans-modules-profiler-actions-SelfSamplerAction.instance"); + if (fo == null) { + return null; + } + Action a = (Action)fo.getAttribute("delegate"); // NOI18N + if (a == null) { + return null; + } + return a.getValue("logger-awt"); // NOI18N + } + + /* long now = System.currentTimeMillis(); ignoreTill = now + PAUSE; long howLong = now - start; @@ -179,7 +209,7 @@ // UI_LOG.log(rec); LOG.log(rec); } - + private static final class EQException extends Exception { private volatile Map stack; @@ -243,4 +273,41 @@ } } + */ + + private static final class NotifySnapshot implements ActionListener { + private final byte[] content; + private final Notification note; + + NotifySnapshot(byte[] arr, long time) { + content = arr; + note = NotificationDisplayer.getDefault().notify( + NbBundle.getMessage(NotifySnapshot.class, "TEQ_LowPerformance"), + ImageUtilities.loadImageIcon("org/netbeans/core/resources/vilik.png", true), + NbBundle.getMessage(NotifySnapshot.class, "TEQ_BlockedFor", time, time / 1000), + this, NotificationDisplayer.Priority.LOW + ); + } + + public void actionPerformed(ActionEvent e) { + try { + FileObject fo = FileUtil.createMemoryFileSystem().getRoot().createData("slow.nps"); + OutputStream os = fo.getOutputStream(); + os.write(content); + os.close(); + final Node obj = DataObject.find(fo).getNodeDelegate(); + Action a = obj.getPreferredAction(); + if (a instanceof ContextAwareAction) { + a = ((ContextAwareAction)a).createContextAwareInstance(Lookups.singleton(obj)); + } + a.actionPerformed(e); + } catch (IOException ex) { + Exceptions.printStackTrace(ex); + } + } + + public void clear() { + note.clear(); + } + } } diff --git a/o.n.core/src/org/netbeans/core/resources/vilik.png b/o.n.core/src/org/netbeans/core/resources/vilik.png new file mode 100644 index 0000000000000000000000000000000000000000..bacd931f5face49bdb50845a35c1396e88b21af8 GIT binary patch literal 876 zc$@)j1C#uTP)Px#24YJ`L;(K){{a7>y{D4^000SaNLh0L01ejw01ejxLMWSf00007bV*G`2iXN0 z2oM21cdWAj000?uMObu0Z*6U5Zgc=ca%Ew3Wn>_CX>@2HM@dakSAh-}0008VNkl3nvV2lz)9wLg)KrK^gdntX;LT~B4vndhX5dY*PCnx#O`Sa&L5?>$z z^?(7W0z5#B6(BC_e*+T0x*|DKoEre4*js=SzPY-Dr+^>mD=|un4sKBt#Jakw`i_nr zCq+q2b$9RT>FXPN45&*a;af@P&;RP(zf-xAT`=y==b}@?|A>#fkNcZ?d;13iflUqD zxBb2^7>ub!^_t-;Ig%v#{q1*~n;SQpOr?az{;I8X#oN7J^Bbqr(x$4pXd;o3T(0sx z(P(N!*Y)sn53pD)Cb!%DQ+c@)S(Y&vojA%^1-f48l+|c7sh&Q4pkrwG^4~pwwELC} zVqJrMO=rM&RuF_zB^FX6k%+0Kr3K?c3{}$>pFMl8xZO5WXlh37I?{S%{QX4YW^exx zfZ+95>#tq$KW}T>T7{M-mrFA+S_O#^N+^TSEs_^ z*&zVw&vV;;?(7U4M&1sE7zRP1)|Eyqna5mvhMCy~c_I1Ypw*c1RFrA9L%XXz^V!@{ zU!x;FJQ{mxFq_LX#0n@VphW;k&EU}$h8Iv}i+^$qJCCXdV7WwV(Ao@$G4I+9TlgrSkqSkJo;@sBGmScYbx zvY5b9;5ML1-?3mGSPjTP8Ylp%?@_Syd}6UwK>r`!qzkE&Kr99T0000 RUNNING = new AtomicReference(); //~ Constructors ------------------------------------------------------------------------------------------------------------- private SelfSamplerAction() { @@ -101,24 +102,6 @@ //~ Methods ------------------------------------------------------------------------------------------------------------------ - /** - * @return the builder - */ - private synchronized StackTraceSnapshotBuilder getBuilder() { - if (builder == null) { - builder = new StackTraceSnapshotBuilder(); - threadFactory = new ThreadFactory() { - public Thread newThread(Runnable r) { - return new Thread(r, THREAD_NAME); - } - }; - builder.setIgnoredThreads(Collections.singleton(THREAD_NAME)); - } - return builder; - } - - - @Override public boolean isEnabled() { return true; @@ -128,42 +111,23 @@ * Invoked when an action occurs. */ public void actionPerformed(final ActionEvent e) { - if (isRunning.compareAndSet(false, true)) { + Controller c; + if (RUNNING.compareAndSet(null, c = new Controller(THREAD_NAME))) { putValue(Action.NAME, ACTION_NAME_STOP); putValue(Action.SMALL_ICON, ImageUtilities.loadImageIcon( "org/netbeans/modules/profiler/actions/resources/modifyProfiling.png" //NOI18N - , false) + , false) ); - final StackTraceSnapshotBuilder b = getBuilder(); - executor = Executors.newSingleThreadScheduledExecutor(threadFactory); - startTime = System.currentTimeMillis(); - executor.scheduleAtFixedRate(new Runnable() { - public void run() { - b.addStacktrace(Thread.getAllStackTraces(), System.nanoTime()); - } - }, 10, 10, TimeUnit.MILLISECONDS); - } else if (isRunning.compareAndSet(true, false)) { + c.run(); + } else if ((c = RUNNING.getAndSet(null)) != null) { putValue(Action.NAME, ACTION_NAME_START); putValue(Action.SMALL_ICON, ImageUtilities.loadImageIcon( "org/netbeans/modules/profiler/actions/resources/openSnapshot.png" //NOI18N - , false) + , false) ); - try { - executor.shutdown(); - executor.awaitTermination(100, TimeUnit.MILLISECONDS); - CPUResultsSnapshot snapshot = getBuilder().createSnapshot(startTime, System.nanoTime()); - LoadedSnapshot loadedSnapshot = new LoadedSnapshot(snapshot, ProfilingSettingsPresets.createCPUPreset(), null, null); - loadedSnapshot.setSaved(true); - ResultsManager.getDefault().openSnapshot(loadedSnapshot); - getBuilder().reset(); - - } catch (CPUResultsSnapshot.NoDataAvailableException ex) { - ex.printStackTrace(); - } catch (InterruptedException ex) { - Thread.currentThread().interrupt(); - } + c.actionPerformed(new ActionEvent(this, 0, "show")); // NOI18N } } @@ -176,5 +140,75 @@ } } + @Override + public Object getValue(String key) { + Object o = super.getValue(key); + if (o == null && key.startsWith("logger-")) { // NOI18N + return new Controller(key); + } + return o; + } + + + private static final class Controller implements Runnable, ActionListener { + private final String name; + private StackTraceSnapshotBuilder builder; + private ThreadFactory threadFactory; + private ScheduledExecutorService executor; + private long startTime; + + public Controller(String n) { + name = n; + } + /** + * @return the builder + */ + private synchronized StackTraceSnapshotBuilder getBuilder() { + if (builder == null) { + builder = new StackTraceSnapshotBuilder(); + threadFactory = new ThreadFactory() { + public Thread newThread(Runnable r) { + return new Thread(r, name); + } + }; + builder.setIgnoredThreads(Collections.singleton(name)); + } + return builder; + } + + public void run() { + final StackTraceSnapshotBuilder b = getBuilder(); + executor = Executors.newSingleThreadScheduledExecutor(threadFactory); + startTime = System.currentTimeMillis(); + executor.scheduleAtFixedRate(new Runnable() { + public void run() { + b.addStacktrace(Thread.getAllStackTraces(), System.nanoTime()); + } + }, 10, 10, TimeUnit.MILLISECONDS); + } + + public void actionPerformed(ActionEvent e) { + try { + executor.shutdown(); + executor.awaitTermination(100, TimeUnit.MILLISECONDS); + if ("cancel".equals(e.getActionCommand())) { + return; + } + CPUResultsSnapshot snapshot = getBuilder().createSnapshot(startTime, System.nanoTime()); + LoadedSnapshot loadedSnapshot = new LoadedSnapshot(snapshot, ProfilingSettingsPresets.createCPUPreset(), null, null); + if ("write".equals(e.getActionCommand())) { + DataOutputStream dos = (DataOutputStream)e.getSource(); + loadedSnapshot.save(dos); + return; + } + loadedSnapshot.setSaved(true); + ResultsManager.getDefault().openSnapshot(loadedSnapshot); + } catch (Exception ex) { + Exceptions.printStackTrace(ex); + } finally { + getBuilder().reset(); + } + } + } } diff --git a/profiler/test/unit/src/org/netbeans/modules/profiler/actions/SelfSamplerActionTest.java b/profiler/test/unit/src/org/netbeans/modules/profiler/actions/SelfSamplerActionTest.java new file mode 100644 --- /dev/null +++ b/profiler/test/unit/src/org/netbeans/modules/profiler/actions/SelfSamplerActionTest.java @@ -0,0 +1,137 @@ +/* + * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS HEADER. + * + * Copyright 2009 Sun Microsystems, Inc. All rights reserved. + * + * The contents of this file are subject to the terms of either the GNU + * General Public License Version 2 only ("GPL") or the Common + * Development and Distribution License("CDDL") (collectively, the + * "License"). You may not use this file except in compliance with the + * License. You can obtain a copy of the License at + * http://www.netbeans.org/cddl-gplv2.html + * or nbbuild/licenses/CDDL-GPL-2-CP. See the License for the + * specific language governing permissions and limitations under the + * License. When distributing the software, include this License Header + * Notice in each file and include the License file at + * nbbuild/licenses/CDDL-GPL-2-CP. Sun designates this + * particular file as subject to the "Classpath" exception as provided + * by Sun in the GPL Version 2 section of the License file that + * accompanied this code. If applicable, add the following below the + * License Header, with the fields enclosed by brackets [] replaced by + * your own identifying information: + * "Portions Copyrighted [year] [name of copyright owner]" + * + * If you wish your version of this file to be governed by only the CDDL + * or only the GPL Version 2, indicate your decision by adding + * "[Contributor] elects to include this software in this distribution + * under the [CDDL or GPL Version 2] license." If you do not indicate a + * single choice of license, a recipient has the option to distribute + * your version of this file under either the CDDL, the GPL Version 2 or + * to extend the choice of license to its licensees as provided above. + * However, if you add GPL Version 2 code and therefore, elected the GPL + * Version 2 license, then the option applies only if the new code is + * made subject to such option by the copyright holder. + * + * Contributor(s): + * + * Portions Copyrighted 2009 Sun Microsystems, Inc. + */ + +package org.netbeans.modules.profiler.actions; + +import java.awt.event.ActionEvent; +import java.awt.event.ActionListener; +import java.io.DataOutputStream; +import java.io.OutputStream; +import java.util.logging.Level; +import javax.swing.Action; +import org.junit.Test; +import org.netbeans.junit.Log; +import org.netbeans.modules.profiler.ui.NpsDataObject; +import org.openide.cookies.OpenCookie; +import org.openide.filesystems.FileObject; +import org.openide.filesystems.FileUtil; +import org.openide.loaders.DataObject; +import static org.junit.Assert.*; + +/** Shows how o.n.core uses the SelfSamplerAction to start and stop self profiling. + * + * @author Jaroslav Tulach + */ +public class SelfSamplerActionTest { + + public SelfSamplerActionTest() { + } + + @Test + public void testSelfProfileToStream() throws Exception { + FileObject afo = FileUtil.getConfigFile("Actions/Profile/org-netbeans-modules-profiler-actions-SelfSamplerAction.instance"); + assertNotNull("SelfSamplerAction is in the right fileobject", afo); + Action a = (Action)afo.getAttribute("delegate"); // NOI18N + Object obj = a.getValue("logger-testprofile"); + assertTrue("It is runnable", obj instanceof Runnable); + assertTrue("It is action listener", obj instanceof ActionListener); + + Runnable r = (Runnable)obj; + ActionListener al = (ActionListener)obj; + + r.run(); + Thread.sleep(1000); + assertLoggerThread("logger-testprofile shall be there", true); + + FileObject fo = FileUtil.createMemoryFileSystem().getRoot().createData("slow.nps"); + OutputStream os = fo.getOutputStream(); + DataOutputStream dos = new DataOutputStream(os); + al.actionPerformed(new ActionEvent(dos, 0, "write")); // NOI18N + dos.close(); + + if (fo.getSize() < 100) { + fail("The file shall have real content: " + fo.getSize()); + } + + DataObject dataObject = DataObject.find(fo); + assertEquals("Nps DataObject", NpsDataObject.class, dataObject.getClass()); + OpenCookie oc = dataObject.getLookup().lookup(OpenCookie.class); + assertNotNull("Open cookie exists", oc); + + CharSequence log = Log.enable("", Level.WARNING); + oc.open(); + + if (log.length() > 0) { + fail("There shall be no warnings:\n" + log); + } + + assertLoggerThread("no logger- thread shall be there", false); + } + + @Test + public void testSelfProfileCancel() throws Exception { + SelfSamplerAction result = SelfSamplerAction.getInstance(); + Object obj = result.getValue("logger-testprofile"); + assertTrue("It is runnable", obj instanceof Runnable); + assertTrue("It is action listener", obj instanceof ActionListener); + + Runnable r = (Runnable)obj; + ActionListener al = (ActionListener)obj; + + r.run(); + Thread.sleep(1000); + assertLoggerThread("logger-testprofile shall be there", true); + + al.actionPerformed(new ActionEvent(this, 0, "cancel")); // NOI18N + + assertLoggerThread("no logger- thread shall be there", false); + } + + private void assertLoggerThread(String msg, boolean exist) { + for (Thread t : Thread.getAllStackTraces().keySet()) { + if (t.getName().startsWith("logger-")) { + assertTrue(msg + "There is " + t.getName() + " thread", exist); + return; + } + } + assertFalse(msg + "There is no logger- thread", exist); + } + + +} \ No newline at end of file