[HACKYSTAT-DEV-L] Debugging NullPointerException discovered a couple of interesting things

[Aaron Kagawa]

Hey Guys,

Austen and I have been tackling a very puzzling error that seems to be caused when testing hackySensor_XmlData. 

The next parts of the email is our debugging quest.... read on if you dare. :)

-------------------------------------------------------------
Here is a short description; when running "ant all.junit" with the following modules

hackyCore_Build.available=true
hackyCore_Kernel.available=true
hackyCore_Installer.available=true
hackyCore_Common.available=true
hackyCore_Report.available=true
hackyCore_Statistics.available=true
hackyCore_Telemetry.available=true
hackySdt_Activity.available=true
hackySdt_BadData.available=true
hackySdt_Coverage.available=true
hackySdt_FileMetric.available=true
hackySdt_UnitTest.available=true
hackySdt_WorkspaceMap.available=true
hackySensor_XmlData.available=true


We see the following error in the Tomcat console:

02/05 21:33:13 Received bad data from: [EMAIL PROTECTED] java.lang.NullPointerException

Ok.. Not much information to go on and no unit tests are failing. 

-------------------------------------------------------------
To start let us describe a couple of strange things we found along the way:

1) Unit Test failures after multiple test executions.

Run the following:
> ant -q freshStart
> ant -q all.junit
> ant -q all.junit

Test cases fail for various hackySdt_* modules on the second all.junit.

2) Running only "ant hackySensor_XmlData.junit" (instead of "ant all.junit") does not reproduce the error.  We have no idea why! I checked the classpaths and everything appears to be ok.

Anyway, I still don't know why hackySensor_XmlData.junit and all.junit do different things.  Thinking about it more.... It seems that the all.junit execution triggers the newEntry alert in JavaClassWorkspaceMapManager and hackySensor_XmlData.junit does not.  This could be a class loader issue, because only SDT code call this class.  So, I guess we can't run a single <module>.junit and hope to be ok. 

3) Another strange thing was that the build\war\download\*.jar files were on the classpath.

    [junit] '-classpath'
    ....
C:\java\svn\hackyCore_Build\build\war\download\sensor.xmldata.jar;
    ...

Not sure if it matters, but does that directory really need to be on the classpath?

-------------------------------------------------------------


Ok Getting back to the real problem:

Austen eventually narrowed it down to one of the test files in hackySensor_XmlData.

So, we added a stack trace printout to the NullPointerException.  Something which we should have done a lot earlier, but we had a lot of problems just reproducing the error on both our machines. Not to mention we got hung up on the previous two problems.

02/05 23:22:18 Received bad data from: [EMAIL PROTECTED] java.lang.NullPointerException
java.lang.NullPointerException
        at org.hackystat.sdt.workspacemap.javamap.JavaClassWorkspaceMapManager.isJavaClassName(JavaClassWorkspaceMapManager.java:642)
        at org.hackystat.sdt.workspacemap.javamap.JavaClassWorkspaceMapManager.updateEntry(JavaClassWorkspaceMapManager.java:558)
        at org.hackystat.sdt.workspacemap.javamap.JavaClassWorkspaceMapManager.newEntry(JavaClassWorkspaceMapManager.java:489)
        at org.hackystat.core.kernel.sensordata.SensorData.add(SensorData.java:115)
        at org.hackystat.core.kernel.soap.Receive.receive(Receive.java:86)
        at sun.reflect.GeneratedMethodAccessor84.invoke(Unknown Source)

We quickly realized that for FileMetric entries that the JavaClassWorkspaceMapManager expects a className with every Java FileMetric entry. Our test filemetric.xml file did not contain a className attribute.  Well, as you may know, className is not a required SDT attribute, so we didn't put it in our test data. Unfortunately, className is required (not in the SDT, but in the background processing in Hackystat) for Java FileMetric entries. Whether or not that is a good thing can be debated later.

Anyway, I think we fixed the problem.. But, we'll make sure after we get some rest from our battles.


-------------------------------------------------------------
Some more strange things (maybe even bugs):

1) I never noticed the following code in org.hackystat.core.kernel.soap.Receive.

      Map keyValStringMap = new HashMap();
      long timeStamp = (new Date()).getTime();
      keyValStringMap.put( "sensorDataType", sdtName);
      keyValStringMap.put( "tool" , sdtName);
      keyValStringMap.put( "tstamp", String.valueOf(timeStamp));
      keyValStringMap.put( "badDataType", "Error receiving data from sensor.");
      keyValStringMap.put( "message", e.toString());
      try {
        SensorDataEntry badData = SensorDataEntryFactory.getEntry( "BadData", keyValStringMap);
        Day day = Day.getInstance(timeStamp);
        SensorData data = "">getInstance().getSensorData(badData.getSdt(), key, day);
        data.add(badData);
        SensorData.storeModifiedSensorData();
      }
      catch (Exception f) {
        String trace2 = StackTrace.toString(f);
        serverProperties.getLogger().warning( "We're hosed. Failure adding Bad Data: " + trace2);
      }

At one point Austen and I were getting the "We're hosed... " message.  Hm... Basically, it seems that hackySdt_BadData should always be required. Otherwise, we could be hosed.


2) The last interesting/strange thing is related to the NullPointerException we were having. One of the reasons why were a little baffled by the NullPointerException was that all of the entries in our test xml files were correctly stored in their respective XML files in the SDT directories. For example,

testdataset\data\FileMetric\2006-02-06.xml contained:
  <entry fileType=".cpp" fileName="foo.cpp" totalLines="9999" tool="CCCC" tstamp="1139222169000" pMap="000200011sourceLines0000255" />
  <entry fileType=".java" fileName="foo.java" totalLines="2300" tool="Locc" tstamp="1139222169001" pMap="000400011sourceLines00004100000007runtime000041000" />

which were the two same entries in our test data.. So, how can one of these entries be causing a problem?  It would seem to us that if one of these were in fact "Bad" then it wouldn't be stored in this file.  We later seen this.

testdataset\data\BadData\2006-02-06.xml contained:
  <entry message="java.lang.NullPointerException" sensorDataType="FileMetric" tool="FileMetric" tstamp="1139222169400" badDataType="Error receiving data from sensor." pMap="0000" />

Ok. so, this BadData entry looks valid. But, where did this bad data come from?  Obviously, we didn't think that it came from our test data.


So, it appears that the Receive BadData function is busted?  Following the stack trace above you will see that because the "missing" className attribute is optional for the SDT therefore the data is stored correctly with SensorDataCache.getInstance().getSensorData(..). But the exception occurs when the listeners are notified ( a couple lines after the call to the cache). Thus, we get two entries, one in FileMetric and one in BadData, for a single incoming entry.

Solving this BadData problem is another email and another night.


thanks, aaron

and thanks to austen for accompanying me on this debugging journey! :)