On 9/22/2010 5:04 PM, Patricia Shanahan wrote:
Meanwhile, I ran some tests under Ubuntu, and one qa.run test got a
NullPointerException in
com/sun/jini/test/spec/eventmailbox/EMSRIFT_PULL2.td
A re-run of the qa.run test that first got the failure did not repeat
it. I have started repeatedly running the one test, and got one more
failure out of 568 runs, so far. I am continuing the repeated run to get
a more statistically significant estimate of the failure rate.
This is obviously going to be difficult to debug, or even to know if we
have fixed it after a change. The bug may have existed for a long time.
I got the following failure on the trunk head revision, with SDM's
addProxyReg modified with a couple of Thread.sleep calls. Note that this
failure is one in thousands of runs, so don't count on reproducing it,
e.g. to get more logging data.
Any ideas what went wrong?
[java] Running com/sun/jini/test/spec/eventmailbox/EMSRIFT_PULL2.td
[java] Time is Wed Sep 22 20:13:06 PDT 2010
[java] Starting test in separate process with command:
[java] /usr/lib/jvm/java-6-openjdk/jre/bin/java
-Djava.security.policy=file:/home/pats/River/qa/harness/policy/defaulttest.policy
-cp
/home/pats/River/qa/lib/jiniharness.jar:/home/pats/River/qa/lib/jinitests.jar:/home/pats/River/lib/jsk-platform.jar:/home/pats/River/lib/jsk-lib.jar
-client
-Djava.ext.dirs=/usr/lib/jvm/java-6-openjdk/jre/lib/ext:/usr/java/packages/lib/ext:/home/pats/River/qa/lib-ext:/home/pats/River/lib-ext
-Dcom.sun.jini.jsk.port=8080 -Dcom.sun.jini.qa.port=8081
-Dcom.sun.jini.jsk.home=/home/pats/River
-Dcom.sun.jini.qa.home=/home/pats/River/qa
-Dcom.sun.jini.qa.harness.harnessJar=/home/pats/River/qa/lib/jiniharness.jar
-Dcom.sun.jini.qa.harness.testJar=/home/pats/River/qa/lib/jinitests.jar
-Dcom.sun.jini.qa.harness.runjiniserver=true
-Dcom.sun.jini.qa.harness.runkitserver=true
-Djava.security.properties=file:/home/pats/River/qa/harness/trust/dynamic-policy.properties
-Dcom.sun.jini.qa.harness.testhosts=
-Djava.util.logging.config.file=/home/pats/River/qa/src/com/sun/jini/test/resources/qa1.logging
-Dcom.sun.jini.test.home=/home/pats/River/qa
-Dcom.sun.jini.test.port=8082
-Dcom.sun.jini.qa.harness.policies=file:/home/pats/River/qa/src/com/sun/jini/test/resources/jinitest.policy
-Djava.ext.dirs=/usr/lib/jvm/java-6-openjdk/jre/lib/ext:/usr/java/packages/lib/ext:/home/pats/River/qa/lib-ext:/home/pats/River/lib-ext
com.sun.jini.qa.harness.MasterTest
com/sun/jini/test/spec/eventmailbox/EMSRIFT_PULL2.td
[java]
[java] TIME: 8:13:06 PM
[java]
[java] MasterTest.doTest INFO:
[java] ============================== CALLING SETUP()
==============================
[java]
[java] Sep 22, 2010 8:13:06 PM com.sun.jini.tool.ClassServer run
[java] INFO: ClassServer started [[/home/pats/River/qa/lib/], port
8081]
[java] Sep 22, 2010 8:13:06 PM com.sun.jini.tool.ClassServer run
[java] INFO: ClassServer started [[/home/pats/River/lib-dl/], port
8080]
[java] Sep 22, 2010 8:13:06 PM com.sun.jini.tool.ClassServer run
[java] INFO: ClassServer started [[/home/pats/River/qa/lib/], port
8082]
[java] MasterTest.doTest INFO:
[java] =============================== CALLING RUN()
===============================
[java]
[java] NonActGrp-out: Sep 22, 2010 8:13:08 PM
com.sun.jini.reggie.RegistrarImpl init
[java] NonActGrp-out: INFO: started Reggie:
3fd8480d-7e19-46fe-a3c9-c0cbd14c27da,
[LDSLookupServiceGroup_UbantuDesktop_1285211586313],
ConstrainableLookupLocator[[jini://UbantuDesktop/], [null]]
[java] NonActGrp-out: Sep 22, 2010 8:13:09 PM
com.sun.jini.mercury.MailboxImpl doInit
[java] NonActGrp-out: INFO: Mercury started:
com.sun.jini.mercury.transientmercuryi...@2b323e
[java] MailboxTestBase.getPullMailbox INFO: Got reference to
PullEventMailbox service:
com.sun.jini.mercury.mailboxproxy$constrainablemailboxpr...@759ce264
[java] MailboxTestBase.getPullRegistration INFO: Got reference to
MailboxPullRegistration object:
com.sun.jini.mercury.registration$constrainableregistrat...@79347b94
[java] MailboxTestBase.getPullRegistration INFO: registration
proxy preparer: BasicProxyPreparer[]
[java] MailboxTestBase.getPullRegistration INFO: Prepared
registration proxy:
com.sun.jini.mercury.registration$constrainableregistrat...@79347b94
[java] MailboxTestBase.getPullMailboxLease INFO: Calling
getPullMailboxLease()
[java] MailboxTestBase.getPullMailboxLease INFO: mailbox lease
preparer: BasicProxyPreparer[]
[java] MailboxTestBase.getPullMailboxLease INFO: Prepared mailbox
lease proxy: LandlordLease:a82734db-3f86-4405-8e84-c90f6011c245
landlord:Proxy[MailboxBackEnd,BasicInvocationHandler[BasicObjectEndpoint[b12586dc-f39e-4d53-a9fd-5eed01e9f487,TcpEndpoint[127.0.1.1:55936]]]]
landlordUuid:106e433a-5c4c-4ccf-9dae-7812a4109583
com.sun.jini.landlord.constrainablelandlordle...@79347b94
[java] MailboxTestBase.checkLease INFO: Lease request for 180000
granted
[java] EMSRIFT_PULL.run INFO: Mailbox lease good untilWed Sep 22
20:16:09 PDT 2010
[java] MailboxTestBase.getPullMailboxListener INFO: Calling
getPullMailboxListener()
[java] MailboxTestBase.getPullMailboxListener INFO: mailbox
listener preparer: BasicProxyPreparer[]
[java] MailboxTestBase.getPullMailboxListener INFO: Prepared
mailbox listener proxy:
com.sun.jini.mercury.listenerproxy$constrainablelistenerpr...@79347b94
[java] MailboxTestBase.checkLease INFO: Lease request for 180000
granted
[java] MailboxTestUtils: createPullListeners: created 1
TestPullListener(s)
[java] EMSRIFT_PULL.run INFO: Generating 5 events
[java] EMSRIFT_PULL.run INFO: Wating for event delivery
[java]
[java] TIME: 8:13:19 PM
[java]
[java] EMSRIFT_PULL.run INFO: Verifying event delivery count of 5
[java] EMSRIFT_PULL.run INFO: Verifying events
[java] NonActGrp-out: ::verifyEvent() verifying
[java] NonActGrp-out: Desired event was found:
com.sun.jini.test.impl.mercury.remoteeventhan...@4d3
[java] NonActGrp-out: Events
are:{com.sun.jini.test.impl.mercury.remoteeventhan...@4d6=net.jini.core.event.remoteevent[source=proxy[testgenerator,BasicInvocationHandler[BasicObjectEndpoint[fe322b99-d59e-424e-9e63-e3b68dc427f8,TcpEndpoint[127.0.1.1:55936]]]]],
com.sun.jini.test.impl.mercury.remoteeventhan...@4d7=net.jini.core.event.remoteevent[source=proxy[testgenerator,BasicInvocationHandler[BasicObjectEndpoint[fe322b99-d59e-424e-9e63-e3b68dc427f8,TcpEndpoint[127.0.1.1:55936]]]]],
com.sun.jini.test.impl.mercury.remoteeventhan...@4d0=net.jini.core.event.remoteevent[source=proxy[testgenerator,BasicInvocationHandler[BasicObjectEndpoint[fe322b99-d59e-424e-9e63-e3b68dc427f8,TcpEndpoint[127.0.1.1:55936]]]]],
com.sun.jini.test.impl.mercury.remoteeventhan...@4d1=net.jini.core.event.remoteevent[source=proxy[testgenerator,BasicInvocationHandler[BasicObjectEndpoint[fe322b99-d59e-424e-9e63-e3b68dc427f8,TcpEndpoint[127.0.1.1:55936]]]]],
com.sun.jini.test.impl.mercury.remoteeventhan...@4d3=net.jini.core.event.remoteevent[source=proxy[testgenerator,BasicInvocationHandler[BasicObjectEndpoint[fe322b99-d59e-424e-9e63-e3b68dc427f8,TcpEndpoint[127.0.1.1:55936]]]]]}
[java] NonActGrp-out: ::verifyEvent() verifying
[java] NonActGrp-out: Desired event was found:
com.sun.jini.test.impl.mercury.remoteeventhan...@4d0
[java] NonActGrp-out: Events
are:{com.sun.jini.test.impl.mercury.remoteeventhan...@4d6=net.jini.core.event.remoteevent[source=proxy[testgenerator,BasicInvocationHandler[BasicObjectEndpoint[fe322b99-d59e-424e-9e63-e3b68dc427f8,TcpEndpoint[127.0.1.1:55936]]]]],
com.sun.jini.test.impl.mercury.remoteeventhan...@4d7=net.jini.core.event.remoteevent[source=proxy[testgenerator,BasicInvocationHandler[BasicObjectEndpoint[fe322b99-d59e-424e-9e63-e3b68dc427f8,TcpEndpoint[127.0.1.1:55936]]]]],
com.sun.jini.test.impl.mercury.remoteeventhan...@4d0=net.jini.core.event.remoteevent[source=proxy[testgenerator,BasicInvocationHandler[BasicObjectEndpoint[fe322b99-d59e-424e-9e63-e3b68dc427f8,TcpEndpoint[127.0.1.1:55936]]]]],
com.sun.jini.test.impl.mercury.remoteeventhan...@4d1=net.jini.core.event.remoteevent[source=proxy[testgenerator,BasicInvocationHandler[BasicObjectEndpoint[fe322b99-d59e-424e-9e63-e3b68dc427f8,TcpEndpoint[127.0.1.1:55936]]]]],
com.sun.jini.test.impl.mercury.remoteeventhan...@4d3=net.jini.core.event.remoteevent[source=proxy[testgenerator,BasicInvocationHandler[BasicObjectEndpoint[fe322b99-d59e-424e-9e63-e3b68dc427f8,TcpEndpoint[127.0.1.1:55936]]]]]}
[java] NonActGrp-out: ::verifyEvent() verifying
[java] NonActGrp-out: Desired event was found:
com.sun.jini.test.impl.mercury.remoteeventhan...@4d1
[java] #
[java] # A fatal error has been detected by the Java Runtime
Environment:
[java] #
[java] # Internal ErrorEMSRIFT_PULL.run INFO: Cancelling
registration lease
[java] (nmethod.cpp:1847), pid=6166, tid=3033299824
[java] # Error: guarantee(cont_offset != 0,"unhandled implicit
exception in compiled code")
[java] #
[java] # JRE version: 6.0_18-b18
[java] # Java VM: OpenJDK Client VM (16.0-b13 mixed mode, sharing
linux-x86 )
[java] # Derivative: IcedTea6 1.8.1
[java] # Distribution: Ubuntu 10.04 LTS, package 6b18-1.8.1-0ubuntu1
[java] # An error report file with more information is saved as:
[java] # /home/pats/River/qa/hs_err_pid6166.log
[java] EMSRIFT_PULL.run INFO: Generating 5 more events
[java] #
[java] # If you would like to submit a bug report, please include
[java] # instructions how to reproduce the bug and visit:
[java] # https://bugs.launchpad.net/ubuntu/+source/openjdk-6/
[java] #
[java] EMSRIFT_PULL.run INFO: Caught NoSuchObjectException - expected
[java] EMSRIFT_PULL.run INFO: Re-cancelling registration lease
[java]
[java] TIME: 8:13:19 PM
[java]
[java] Test process was destroyed and returned code 134
[java] com/sun/jini/test/spec/eventmailbox/EMSRIFT_PULL2.td
[java] Test Failed: Test VM terminated without returning test status
