4 Replies Latest reply on May 19, 2014 3:55 PM by Raj Jamadagni

    V4.0.2: Trace file analysis issue

    Raj Jamadagni

      Are their limits on size of tracefile that SQLDev can analyze? I am trying to have to read a file which is 4.32G and it just hangs. This is the stack trace after about 10 minutes or so

       

      C:\SqlDev4.2\sqldeveloper\sqldeveloper\bin>2014-05-16 09:17:18

      Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.55-b03 mixed mode):

       

      "Swing-Shell" daemon prio=6 tid=0x0000000011229000 nid=0x2644 waiting on condition [0x000000001674f000]

         java.lang.Thread.State: WAITING (parking)

              at sun.misc.Unsafe.park(Native Method)

              - parking to wait for  <0x00000000d2025020> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)

              at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)

              at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)

              at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)

              at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)

              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)

              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

              at sun.awt.shell.Win32ShellFolderManager2$ComInvoker$3.run(Win32ShellFolderManager2.java:503)

              at java.lang.Thread.run(Thread.java:745)

       

      "status-0" prio=2 tid=0x0000000011227000 nid=0x2640 waiting on condition [0x0000000014d4f000]

         java.lang.Thread.State: WAITING (parking)

              at sun.misc.Unsafe.park(Native Method)

              - parking to wait for  <0x00000000d1c939d8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)

              at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)

              at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)

              at java.util.concurrent.DelayQueue.take(DelayQueue.java:209)

              at oracle.ide.status.StatusExecutor$StatusQueue.take(StatusExecutor.java:338)

              at oracle.ide.status.StatusExecutor$StatusQueue.take(StatusExecutor.java:300)

              at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)

              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)

              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

              at java.lang.Thread.run(Thread.java:745)

       

      "IconOverlayTracker Timer: null-jdbcNodeInfoType" prio=6 tid=0x0000000011228800 nid=0x125c in Object.wait() [0x000000001654f000]

         java.lang.Thread.State: WAITING (on object monitor)

              at java.lang.Object.wait(Native Method)

              - waiting on <0x00000000d1bda1d8> (a java.util.TaskQueue)

              at java.lang.Object.wait(Object.java:503)

              at java.util.TimerThread.mainLoop(Timer.java:526)

              - locked <0x00000000d1bda1d8> (a java.util.TaskQueue)

              at java.util.TimerThread.run(Timer.java:505)

       

      "WaitCursor-Timer" prio=6 tid=0x0000000011225800 nid=0x17a8 in Object.wait() [0x0000000014b4f000]

         java.lang.Thread.State: WAITING (on object monitor)

              at java.lang.Object.wait(Native Method)

              - waiting on <0x00000000d16b3708> (a java.util.TaskQueue)

              at java.lang.Object.wait(Object.java:503)

              at java.util.TimerThread.mainLoop(Timer.java:526)

              - locked <0x00000000d16b3708> (a java.util.TaskQueue)

              at java.util.TimerThread.run(Timer.java:505)

       

      "WeakDataReference polling" prio=2 tid=0x0000000011226000 nid=0x1bf8 in Object.wait() [0x0000000014c4f000]

         java.lang.Thread.State: WAITING (on object monitor)

              at java.lang.Object.wait(Native Method)

              - waiting on <0x00000000d0aa45b8> (a java.lang.ref.ReferenceQueue$Lock)

              at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)

              - locked <0x00000000d0aa45b8> (a java.lang.ref.ReferenceQueue$Lock)

              at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)

              at oracle.ide.util.WeakDataReference$Cleaner.run(WeakDataReference.java:88)

              at java.lang.Thread.run(Thread.java:745)

       

      "pool-2-thread-1" prio=6 tid=0x0000000011224800 nid=0x1b5c waiting on condition [0x00000000136ff000]

         java.lang.Thread.State: WAITING (parking)

              at sun.misc.Unsafe.park(Native Method)

              - parking to wait for  <0x00000000d028a808> (a java.util.concurrent.SynchronousQueue$TransferStack)

              at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)

              at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458)

              at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:359)

              at java.util.concurrent.SynchronousQueue.take(SynchronousQueue.java:925)

              at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)

              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)

              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

              at java.lang.Thread.run(Thread.java:745)

       

      "Scheduler" daemon prio=6 tid=0x0000000011224000 nid=0x1db0 in Object.wait() [0x000000001348f000]

         java.lang.Thread.State: WAITING (on object monitor)

              at java.lang.Object.wait(Native Method)

              - waiting on <0x00000000d028a270> (a oracle.dbtools.raptor.backgroundTask.TaskLinkedList)

              at java.lang.Object.wait(Object.java:503)

              at oracle.dbtools.raptor.backgroundTask.TaskLinkedList.takeNextTask(TaskLinkedList.java:47)

              - locked <0x00000000d028a270> (a oracle.dbtools.raptor.backgroundTask.TaskLinkedList)

              at oracle.dbtools.raptor.backgroundTask.RaptorTaskManager$SchedulerThread.run(RaptorTaskManager.java:479)

       

      "Thread-9" daemon prio=6 tid=0x000000000d72f000 nid=0x2518 in Object.wait() [0x000000001228f000]

         java.lang.Thread.State: WAITING (on object monitor)

              at java.lang.Object.wait(Native Method)

              - waiting on <0x00000000cf2bb1e0> (a java.util.LinkedList)

              at java.lang.Object.wait(Object.java:503)

              at java.util.prefs.AbstractPreferences$EventDispatchThread.run(AbstractPreferences.java:1476)

              - locked <0x00000000cf2bb1e0> (a java.util.LinkedList)

       

      "Log Poller" prio=2 tid=0x000000000d72e800 nid=0x237c waiting on condition [0x00000000135ff000]

         java.lang.Thread.State: WAITING (parking)

              at sun.misc.Unsafe.park(Native Method)

              - parking to wait for  <0x00000000cf587ed0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)

              at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)

              at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)

              at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)

              at oracle.ide.log.QueuedLoggingHandler.take(QueuedLoggingHandler.java:60)

              at oracle.ideimpl.log.TabbedLogManager$4.run(TabbedLogManager.java:321)

              at java.lang.Thread.run(Thread.java:745)

       

      "JarIndex Timer" daemon prio=6 tid=0x000000000d72d000 nid=0x1b90 in Object.wait() [0x000000001208f000]

         java.lang.Thread.State: TIMED_WAITING (on object monitor)

              at java.lang.Object.wait(Native Method)

              - waiting on <0x00000000cfb8d4b8> (a java.util.TaskQueue)

              at java.util.TimerThread.mainLoop(Timer.java:552)

              - locked <0x00000000cfb8d4b8> (a java.util.TaskQueue)

              at java.util.TimerThread.run(Timer.java:505)

       

      "TimedCache-Timer" daemon prio=6 tid=0x000000000d72b800 nid=0x153c in Object.wait() [0x0000000010d7f000]

         java.lang.Thread.State: TIMED_WAITING (on object monitor)

              at java.lang.Object.wait(Native Method)

              - waiting on <0x00000000cf8a8a78> (a java.util.TaskQueue)

              at java.util.TimerThread.mainLoop(Timer.java:552)

              - locked <0x00000000cf8a8a78> (a java.util.TaskQueue)

              at java.util.TimerThread.run(Timer.java:505)

       

      "Framework Event Dispatcher" daemon prio=6 tid=0x000000000d729000 nid=0x21f4 in Object.wait() [0x000000000fbaf000]

         java.lang.Thread.State: WAITING (on object monitor)

              at java.lang.Object.wait(Native Method)

              - waiting on <0x00000000cebb4810> (a org.eclipse.osgi.framework.eventmgr.EventManager$EventThread)

              at java.lang.Object.wait(Object.java:503)

              at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.getNextEvent(EventManager.java:400)

              - locked <0x00000000cebb4810> (a org.eclipse.osgi.framework.eventmgr.EventManager$EventThread)

              at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:336)

       

      "Framework Active Thread" prio=6 tid=0x000000000d8a9800 nid=0x25dc in Object.wait() [0x000000000f83f000]

         java.lang.Thread.State: TIMED_WAITING (on object monitor)

              at java.lang.Object.wait(Native Method)

              - waiting on <0x00000000ceb490f0> (a org.eclipse.osgi.framework.internal.core.Framework)

              at org.eclipse.osgi.framework.internal.core.Framework.run(Framework.java:1863)

              - locked <0x00000000ceb490f0> (a org.eclipse.osgi.framework.internal.core.Framework)

              at java.lang.Thread.run(Thread.java:745)

       

      "Active Reference Queue Daemon" daemon prio=2 tid=0x000000000d555800 nid=0x146c in Object.wait() [0x000000000e08f000]

         java.lang.Thread.State: TIMED_WAITING (on object monitor)

              at java.lang.Object.wait(Native Method)

              - waiting on <0x00000000ce9c08c0> (a java.lang.ref.ReferenceQueue$Lock)

              at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)

              - locked <0x00000000ce9c08c0> (a java.lang.ref.ReferenceQueue$Lock)

              at org.openide.util.lookup.implspi.ActiveQueue$Daemon.run(ActiveQueue.java:180)

              - locked <0x00000000ce9c08c0> (a java.lang.ref.ReferenceQueue$Lock)

       

      "TimerQueue" daemon prio=6 tid=0x000000000a550800 nid=0x1ecc waiting on condition [0x000000000ddcf000]

         java.lang.Thread.State: WAITING (parking)

              at sun.misc.Unsafe.park(Native Method)

              - parking to wait for  <0x00000000cea2e9f0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)

              at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)

              at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)

              at java.util.concurrent.DelayQueue.take(DelayQueue.java:209)

              at javax.swing.TimerQueue.run(TimerQueue.java:171)

              at java.lang.Thread.run(Thread.java:745)

       

      "AWT-EventQueue-0" prio=6 tid=0x000000000a479000 nid=0x1568 runnable [0x000000000c09d000]

         java.lang.Thread.State: RUNNABLE

              at java.lang.String.substring(String.java:1913)

              at java.util.StringTokenizer.nextToken(StringTokenizer.java:352)

              at oracle.dbtools.raptor.sqltrace.parser.EventExecute.trimPLH(EventExecute.java:80)

              at oracle.dbtools.raptor.sqltrace.parser.EventExecute.<init>(EventExecute.java:47)

              at oracle.dbtools.raptor.sqltrace.parser.SqlCursor.addEvent(SqlCursor.java:155)

              at oracle.dbtools.raptor.sqltrace.parser.TraceFile.shred(TraceFile.java:184)

              at oracle.dbtools.raptor.sqltrace.SqlTraceEditorNode.getTraceFile(SqlTraceEditorNode.java:27)

              at oracle.dbtools.raptor.sqltrace.SqlTraceTreeEditor.init(SqlTraceTreeEditor.java:45)

              at oracle.dbtools.raptor.sqltrace.SqlTraceTreeEditor.getGUI(SqlTraceTreeEditor.java:60)

              at com.oracle.jdeveloper.nbwindowsystem.editor.SplitPane.attachEditor(SplitPane.java:1119)

              at com.oracle.jdeveloper.nbwindowsystem.editor.SplitPane.attachNewEditor(SplitPane.java:1113)

              at com.oracle.jdeveloper.nbwindowsystem.editor.SplitPane.doLayout(SplitPane.java:586)

              at com.oracle.jdeveloper.nbwindowsystem.NbEditorManager.whenCurrentEditorChanges(NbEditorManager.java:1591)

              at com.oracle.jdeveloper.nbwindowsystem.editor.TabGroup.whenCurrentEditorChanges(TabGroup.java:1026)

              at com.oracle.jdeveloper.nbwindowsystem.editor.TabGroup.setCurrentTabGroupState(TabGroup.java:847)

              at com.oracle.jdeveloper.nbwindowsystem.editor.TabGroup.addTabGroupState(TabGroup.java:129)

              at com.oracle.jdeveloper.nbwindowsystem.NbEditorManager.createEditor(NbEditorManager.java:546)

              at com.oracle.jdeveloper.nbwindowsystem.NbEditorManager.createEditor(NbEditorManager.java:523)

              at com.oracle.jdeveloper.nbwindowsystem.NbEditorManager.openEditor(NbEditorManager.java:391)

              at oracle.ide.cmd.OpenCommand.openWithNoProject(OpenCommand.java:337)

              at oracle.ide.cmd.OpenCommand.access$100(OpenCommand.java:62)

              at oracle.ide.cmd.OpenCommand$1.run(OpenCommand.java:266)

              at java.awt.event.InvocationEvent.dispatch(InvocationEvent.java:312)

              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 oracle.javatools.internal.ui.EventQueueWrapper._dispatchEvent(EventQueueWrapper.java:169)

              at oracle.javatools.internal.ui.EventQueueWrapper.dispatchEvent(EventQueueWrapper.java:151)

              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)

       

      "AWT-Windows" daemon prio=6 tid=0x000000000a478000 nid=0x1b64 runnable [0x000000000be9f000]

         java.lang.Thread.State: RUNNABLE

              at sun.awt.windows.WToolkit.eventLoop(Native Method)

              at sun.awt.windows.WToolkit.run(WToolkit.java:307)

              at java.lang.Thread.run(Thread.java:745)

       

      "AWT-Shutdown" prio=6 tid=0x000000000a475800 nid=0x2534 in Object.wait() [0x000000000bd9f000]

         java.lang.Thread.State: WAITING (on object monitor)

              at java.lang.Object.wait(Native Method)

              - waiting on <0x00000000ceaec208> (a java.lang.Object)

              at java.lang.Object.wait(Object.java:503)

              at sun.awt.AWTAutoShutdown.run(AWTAutoShutdown.java:296)

              - locked <0x00000000ceaec208> (a java.lang.Object)

              at java.lang.Thread.run(Thread.java:745)

       

      "Java2D Disposer" daemon prio=10 tid=0x000000000a474800 nid=0x1dc8 in Object.wait() [0x000000000bc9f000]

         java.lang.Thread.State: WAITING (on object monitor)

              at java.lang.Object.wait(Native Method)

              - waiting on <0x00000000ce9d6908> (a java.lang.ref.ReferenceQueue$Lock)

              at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)

              - locked <0x00000000ce9d6908> (a java.lang.ref.ReferenceQueue$Lock)

              at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)

              at sun.java2d.Disposer.run(Disposer.java:145)

              at java.lang.Thread.run(Thread.java:745)

       

      "Service Thread" daemon prio=6 tid=0x000000000a2db000 nid=0x1d2c runnable [0x0000000000000000]

         java.lang.Thread.State: RUNNABLE

       

      "C2 CompilerThread1" daemon prio=10 tid=0x000000000a2d6000 nid=0x1358 waiting on condition [0x0000000000000000]

         java.lang.Thread.State: RUNNABLE

       

      "C2 CompilerThread0" daemon prio=10 tid=0x000000000912a800 nid=0x1f40 waiting on condition [0x0000000000000000]

         java.lang.Thread.State: RUNNABLE

       

      "Attach Listener" daemon prio=10 tid=0x0000000009129000 nid=0x1f8c runnable [0x0000000000000000]

         java.lang.Thread.State: RUNNABLE

       

      "Signal Dispatcher" daemon prio=10 tid=0x0000000009128000 nid=0x21bc waiting on condition [0x0000000000000000]

         java.lang.Thread.State: RUNNABLE

       

      "Finalizer" daemon prio=8 tid=0x0000000009116000 nid=0x2430 in Object.wait() [0x000000000b4df000]

         java.lang.Thread.State: WAITING (on object monitor)

              at java.lang.Object.wait(Native Method)

              - waiting on <0x00000000ce4c37b8> (a java.lang.ref.ReferenceQueue$Lock)

              at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)

              - locked <0x00000000ce4c37b8> (a java.lang.ref.ReferenceQueue$Lock)

              at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)

              at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:189)

       

      "Reference Handler" daemon prio=10 tid=0x000000000910e000 nid=0x65c in Object.wait() [0x000000000b3df000]

         java.lang.Thread.State: WAITING (on object monitor)

              at java.lang.Object.wait(Native Method)

              - waiting on <0x00000000ce497900> (a java.lang.ref.Reference$Lock)

              at java.lang.Object.wait(Object.java:503)

              at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)

              - locked <0x00000000ce497900> (a java.lang.ref.Reference$Lock)

       

      "main" prio=6 tid=0x000000000265b000 nid=0x1ef4 waiting on condition [0x0000000000000000]

         java.lang.Thread.State: RUNNABLE

       

      "VM Thread" prio=10 tid=0x00000000026eb800 nid=0x2684 runnable

      "GC task thread#0 (ParallelGC)" prio=6 tid=0x0000000002671800 nid=0x224c runnable

      "GC task thread#1 (ParallelGC)" prio=6 tid=0x0000000002673800 nid=0x2270 runnable

      "GC task thread#2 (ParallelGC)" prio=6 tid=0x0000000002675000 nid=0x2358 runnable

      "GC task thread#3 (ParallelGC)" prio=6 tid=0x0000000002676800 nid=0x1564 runnable

      "GC task thread#4 (ParallelGC)" prio=6 tid=0x000000000267a000 nid=0x14bc runnable

      "GC task thread#5 (ParallelGC)" prio=6 tid=0x000000000267b800 nid=0x16bc runnable

      "GC task thread#6 (ParallelGC)" prio=6 tid=0x000000000267c800 nid=0x1b9c runnable

      "GC task thread#7 (ParallelGC)" prio=6 tid=0x000000000267e000 nid=0xdac runnable

      "VM Periodic Task Thread" prio=10 tid=0x000000000a2ed000 nid=0x20b4 waiting on condition

      JNI global references: 1672

       

      Heap

      PSYoungGen      total 244736K, used 217969K [0x00000000ef500000, 0x00000000ffd00000, 0x0000000100000000)

        eden space 218112K, 99% used [0x00000000ef500000,0x00000000fc9f9668,0x00000000fca00000)

        from space 26624K, 0% used [0x00000000fe300000,0x00000000fe300000,0x00000000ffd00000)

        to   space 25600K, 0% used [0x00000000fca00000,0x00000000fca00000,0x00000000fe300000)

      ParOldGen       total 545792K, used 545631K [0x00000000ce000000, 0x00000000ef500000, 0x00000000ef500000)

        object space 545792K, 99% used [0x00000000ce000000,0x00000000ef4d7c68,0x00000000ef500000)

      PSPermGen       total 71680K, used 71554K [0x00000000be000000, 0x00000000c2600000, 0x00000000ce000000)

        object space 71680K, 99% used [0x00000000be000000,0x00000000c25e0b60,0x00000000c2600000)

        • 1. Re: V4.0.2: Trace file analysis issue
          thatJeffSmith-Oracle

          The tool doesn't per se, but trying to open a 4GB+ file is probably asking for too much

          • 2. Re: V4.0.2: Trace file analysis issue
            Raj Jamadagni

            Well, that is how big the file is. Never mind, I used another tool, but wanted to see if SQLDEV had any limitations,

             

            Thanks

            • 3. Re: V4.0.2: Trace file analysis issue
              Gary Graham-Oracle

              It is always good to find an appropriate tool for any given task.  Even though SQL Developer can process large SQL trace files, particularly on 64-bit systems having lots of RAM and a multi-gigabyte value for the Java virtual machine's memory limit, I think a 4.32 GB file classifies as huge.  It is simply way beyond the planned scope of the tool.

               

              The intended mission would more likely be:

              1. Open a worksheet session X on a connection.

              2. Use Tools > Monitor Sessions, connecting  as a user with appropriate authority, right-click on session X > Trace Session.

              3. Run the SQL statement or script you wish to trace from the worksheet.

              4. Let the SQL run to completion or right-click on session X > Kill Session if it runs longer than you wish to wait.

              5. File > Open on the resulting trace file (or drag & drop into the worksheet).

               

              Huge trace files with, say, all database sessions for a limited time, or one session for an extended time, are best processed with other tools or utilities.  As the memory required by SQL Developer to process a given file may be several times its size on disk, my advice would be to avoid anything more than 50 MB, depending on the JVM's memory settings. 

               

              Regards,

              Gary

              SQL Developer Team

              • 4. Re: V4.0.2: Trace file analysis issue
                Raj Jamadagni

                Gary Graham wrote:

                 

                It is always good to find an appropriate tool for any given task.

                Unfortunately I couldn't easily find a documented limit on file size that SQLDEV can successfully process, hence this question was posted. Now that you have laid out the expected scenario, in most cases I will have to stick to other tools. Not that it is an issue, but good to know.

                 

                Thanks