Some Eclipse Foundation services are deprecated, or will be soon. Please ensure you've read this important communication.

Bug 196013

Summary: NPE in Execution Flow after Pause/Resume test
Product: z_Archived Reporter: Jonathan West <jgwest>
Component: TPTPAssignee: Eugene Chan <ewchan>
Status: CLOSED FIXED QA Contact:
Severity: critical    
Priority: P1 CC: analexee, asaf.yaffe, guru.nagarajan, jkubasta, ruslan.scherbakov, slavescu, sluiman
Version: unspecified   
Target Milestone: ---   
Hardware: PC   
OS: Windows XP   
Whiteboard: closed460
Bug Depends on:    
Bug Blocks: 191809, 196198    
Attachments:
Description Flags
Proposed fix
none
TI trace file
none
PI trace file
none
.log file
none
Proposed fix2
none
patch none

Description Jonathan West CLA 2007-07-10 12:27:32 EDT
Build ID: I20070625-1500

Steps To Reproduce:
1. Launch InOut in controlled mode. e.g. java -agentlib:JPIBootLoader=JPIAgent:server=controlled;CGProf InOut

2. In Eclipse, open the profile dialog, create a new Attach entry for InOut, and specify "Show execution flow graphical details" under Execution Time Analysis (Agents tab).

3. Open the Execution Statistics view after the entry prompt is displayed in the Profiling Console. Refresh the view until no additional data is shown.

4. Pause the agent
5. Press enter in the profiling console. 
6. Resume the agent
7. Press enter in the profiling console. 

8. Open Execution Flow. Under 'Thread name'->main[xxxx]->main(java.lang.String[]), you should see an entry "unknownXXXXX()", where XXXXX is a set of numbers (in my case 69256). Double click the entry.

Dialog pops up indicating "IWAT0288E Error opening Execution Flow Table view" in the title bar, and 'Reason: java.lang.NullPointerException" in the body of the dialog.

More information:
Using TPTP-4.4.0.1-200707090100. IBM JDK 1.5 SR5.
Comment 1 Jonathan West CLA 2007-07-10 13:43:22 EDT
I have also reproduced this in Linux on a separate machine. Same build.
Comment 2 Ruslan Scherbakov CLA 2007-07-11 04:24:23 EDT
Created attachment 73514 [details]
Proposed fix

This fix contains small null pointer check in org.eclipse.hyades.trace.views plugin.

Please review and check into CVS. I do not have write access to this plugin.
Comment 3 Ruslan Scherbakov CLA 2007-07-11 04:26:50 EDT
The fix is based on the following call stack:

java.lang.NullPointerException
	at org.eclipse.hyades.trace.views.internal.MultiLevelStatisticView.select(MultiLevelStatisticView.java:425)
	at org.eclipse.hyades.trace.views.internal.MultiLevelStatisticView.handleSelectionEvent(MultiLevelStatisticView.java:380)
	at org.eclipse.hyades.trace.views.internal.MultiLevelStatisticView.handleViewSelectionChangedEvent(MultiLevelStatisticView.java:671)
	at org.eclipse.tptp.platform.common.ui.trace.internal.helpers.TraceUIManager.notifyViewSelectionChangedListener(TraceUIManager.java:390)
	at org.eclipse.hyades.trace.ui.UIPlugin.notifyViewSelectionChangedListener(UIPlugin.java:550)
	at org.eclipse.hyades.trace.views.internal.StatisticView.notifyViewSelectionChanged(StatisticView.java:1042)
	at org.eclipse.hyades.trace.views.internal.ExecutionStatistic.updateModelSelection(ExecutionStatistic.java:520)
	at org.eclipse.hyades.trace.views.internal.StatisticView.widgetSelected(StatisticView.java:525)
	at org.eclipse.swt.widgets.TypedListener.handleEvent(TypedListener.java:227)
	at org.eclipse.swt.widgets.EventTable.sendEvent(EventTable.java:66)
	at org.eclipse.swt.widgets.Widget.sendEvent(Widget.java:938)
	at org.eclipse.swt.widgets.Display.runDeferredEvents(Display.java:3682)
	at org.eclipse.swt.widgets.Display.readAndDispatch(Display.java:3293)
	at org.eclipse.ui.internal.Workbench.runEventLoop(Workbench.java:2389)
	at org.eclipse.ui.internal.Workbench.runUI(Workbench.java:2353)
	at org.eclipse.ui.internal.Workbench.access$4(Workbench.java:2219)
	at org.eclipse.ui.internal.Workbench$4.run(Workbench.java:466)
	at org.eclipse.core.databinding.observable.Realm.runWithDefault(Realm.java:289)
	at org.eclipse.ui.internal.Workbench.createAndRunWorkbench(Workbench.java:461)
	at org.eclipse.ui.PlatformUI.createAndRunWorkbench(PlatformUI.java:149)
	at org.eclipse.ui.internal.ide.application.IDEApplication.start(IDEApplication.java:106)
	at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:153)
	at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:106)
	at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:76)
	at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:363)
	at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:176)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
	at java.lang.reflect.Method.invoke(Method.java:585)
	at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:504)
	at org.eclipse.equinox.launcher.Main.basicRun(Main.java:443)
	at org.eclipse.equinox.launcher.Main.run(Main.java:1169)
Comment 4 Eugene Chan CLA 2007-07-11 11:48:54 EDT
The patch only captures the null point exception but the main concern here is the existence of an 'unknown' entry in the table.

The unknown entry comes from MethodEntry and MethodExit of a method that does not have a MethodDef. The method is called during the pause period and so it's not sent to WB.

Comparing between the TI and PI trace, PI never send any methodEntry/Exit calls of method that is created during a pause/detach period, while TI will send all events in a monitored period no matter when the method was defined. I think both has their pro and cons, but showing 'unknown' is useless to user, unless methodDef is cached during a pause period and flushed to WB client as soon as monitor is resumed.
Comment 5 Eugene Chan CLA 2007-07-11 11:55:37 EDT
Created attachment 73558 [details]
TI trace file
Comment 6 Eugene Chan CLA 2007-07-11 11:56:01 EDT
Created attachment 73559 [details]
PI trace file
Comment 7 Harm Sluiman CLA 2007-07-11 12:39:41 EDT
(In reply to comment #4)
> The patch only captures the null point exception but the main concern here is
> the existence of an 'unknown' entry in the table.
> The unknown entry comes from MethodEntry and MethodExit of a method that does
> not have a MethodDef. The method is called during the pause period and so it's
> not sent to WB.
> Comparing between the TI and PI trace, PI never send any methodEntry/Exit calls
> of method that is created during a pause/detach period, while TI will send all
> events in a monitored period no matter when the method was defined. I think
> both has their pro and cons, but showing 'unknown' is useless to user, unless
> methodDef is cached during a pause period and flushed to WB client as soon as
> monitor is resumed.

A key pattern is that entry exit and other events that were not preceded with a def event are handled as an error condition by the workbench, and this creates unknown objects in the model. Historically the unknown is cleaned up, if and when the def does arrive, but I have not looked the code is a few years and this behaviour may no longer be consistent. Aside from how agents can avoid sending events that trigger error recovery in the loaders, the key is that they behave the same and don't drive error handling as a normal use path. It is easy to see how different agents could provide different implementations of tracking, caching or noop. We now have 3 that we ship (ARM, PI, TI) and there are others that build on top of us so our client side behaviour needs to be safe and predictable.
It seems for this defect in 4.4.0.1 we need to accept this patch for the immediate symptom, and open a new high severity defect to track proper resolution asap after 4.4.0.1
Comment 8 Eugene Chan CLA 2007-07-11 13:50:32 EDT
Ruslan, there are still areas that the patch does not cover. Please see my attach .log file for detail.
Comment 9 Eugene Chan CLA 2007-07-11 13:52:22 EDT
Created attachment 73574 [details]
.log file

NPEs is capture is the following areas:
1.org.eclipse.hyades.trace.views.internal.view.columnlabels.PackageNameColumnLabel.getTRCPackage(PackageNameColumnLabel.java:69)
2.org.eclipse.hyades.trace.views.adapter.internal.MethodDetailsTab.setViewTitle(MethodDetailsTab.java:163)
3.org.eclipse.hyades.trace.views.internal.view.columnlabels.PackageNameColumnLabel.getTRCPackage(PackageNameColumnLabel.java:69)
Comment 10 Asaf Yaffe CLA 2007-07-11 15:52:57 EDT
"unknown" entries in the various JVMTI Profilers were previously encountered in bug 190687 and were caused by bug 193304 (both marked as FIXED). All JVMTI Profilers cache methodDef and classDef events during pause and transmit them when data collection is resumed. Due to bug 193304, some of these events did not reach the workbench, and thus caused the "unknown" entries to appear. Either bug 193304 was not fully fixed and should be reopened, or this is a new bug in the JVMTI Profiler runtime.
Comment 11 Ruslan Scherbakov CLA 2007-07-12 06:46:51 EDT
Created attachment 73648 [details]
Proposed fix2

I reproduced and added more two null ptr fixes:
  PackageNameColumnLabel.java:69
  MethodDetailsTab.java:163

Please review this .

This bug was already approved for check in. I do not know whether this bug should be rerequested for approve one more time or second patch can be checked into CVS.
Comment 12 Harm Sluiman CLA 2007-07-12 07:39:48 EDT
> This bug was already approved for check in. I do not know whether this bug
> should be rerequested for approve one more time or second patch can be checked
> into CVS.

In light of the other fixes needed and the need to investigate the root cause of hte incomplete models this fix has not made it into the final 4.4.0.1 which we have to deliver later today. It is certainly an important candidate for the very limited 4.4.0.2 tha thas been proposed.
Comment 13 jkubasta CLA 2007-07-12 08:25:38 EDT
*** Bug 196198 has been marked as a duplicate of this bug. ***
Comment 14 Asaf Yaffe CLA 2007-07-12 09:00:17 EDT
I suggest we use this bugzilla to track the status of the NPE error, and use bug 196198 to track the status of the "unknown" entries in the UI.
Comment 15 Eugene Chan CLA 2007-07-12 17:52:57 EDT
Created attachment 73705 [details]
patch

Ruslan, The patch looks good. I have update a few thing in your patch and here is the latest version.
Comment 16 Eugene Chan CLA 2007-07-12 17:54:13 EDT
The latest patch now covers all errors shown in the user case.

Thanks again to Ruslan.
Comment 17 Ruslan Scherbakov CLA 2007-07-13 08:39:36 EDT
Eugene,

I have sent request for approval.
Check in the final patch into CVS please if the request will be approved.
Comment 18 Ruslan Scherbakov CLA 2007-07-16 03:27:16 EDT
Eugene,
As I do not have write access to in org.eclipse.hyades.trace.views, please check in the patch in 4402 according to Harm's approval:

>>
agreed on 4402  once it is created
note this will mean the change needs to go into the 4402 stream and the head stream 
<<
Comment 19 Paul Slauenwhite CLA 2007-07-16 09:10:08 EDT
Triaging 4.4.0.2 candidate defects for Joanna.  

This is a 4.4.0.2 candidate defect since deferred from 4.4.0.1 and a patch is attached.

Eugene, please target to 4.4.0.2 when the field is available and provide a
sizing.
Comment 20 Guru Nagarajan CLA 2007-07-19 10:56:38 EDT
I recommend that the attached Patch be not applied until  196198 is resolved.
The patch is essentially suppressing the exception.

Once patch  196198 is resolved then we ought to test to see if we still get the exceptions and apply this to ensure we have not masked any unknown exceptions.
Comment 21 Eugene Chan CLA 2007-08-13 17:32:49 EDT
update target, blocked by defect bug 196198.
Comment 22 Guru Nagarajan CLA 2007-08-24 13:31:27 EDT
Eugene, The dependent defects have been resolved. Can you check in the attached patch
Comment 23 Eugene Chan CLA 2007-08-24 15:45:17 EDT
Patch is tested and submitted.
Comment 24 Paul Slauenwhite CLA 2009-06-30 13:59:44 EDT
As of TPTP 4.6.0, TPTP is in maintenance mode and focusing on improving quality by resolving relevant enhancements/defects and increasing test coverage through test creation, automation, Build Verification Tests (BVTs), and expanded run-time execution. As part of the TPTP Bugzilla housecleaning process (see http://wiki.eclipse.org/Bugzilla_Housecleaning_Processes), this enhancement/defect is verified/closed by the Project Lead since this enhancement/defect has been resolved and unverified for more than 1 year and considered to be fixed. If this enhancement/defect is still unresolved and reproducible in the latest TPTP release (http://www.eclipse.org/tptp/home/downloads/), please re-open.