db-derby-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Robert Yokota (JIRA)" <j...@apache.org>
Subject [jira] Updated: (DERBY-3260) NullPointerException caused by race condition in GenericActivationHolder
Date Fri, 07 Dec 2007 01:51:43 GMT

     [ https://issues.apache.org/jira/browse/DERBY-3260?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Robert Yokota updated DERBY-3260:
---------------------------------

    Description: 
I have a stress test using Derby 10.3.1.4 which is executing the same PreparedStatement using
multiple threads concurrently and I consistently get the following NPE after several hours
of running:

2007-12-07 00:48:10.914 GMT Thread[pool-5-thread-25,5,main] (XID = 1219661), (SESSIONID =
377), (DATABASE = /usr/ironhide/var/db/opera/derby), (DRDAID = null), Failed Statement is:
select rdbmsvaria0_.GUID_AND_INDEX as GUID1_3_0_, rdbmsvaria0_.VALUE2 as VALUE2_3_0_, rdbmsvaria0_.HOLDER_GUID
as HOLDER3_3_0_, rdbmsvaria0_.VALUE_TYPE as VALUE4_3_0_, rdbmsvaria0_.VALUE_GUID as VALUE5_3_0_,
rdbmsvaria0_.DELETED as DELETED3_0_ from VARIABLE rdbmsvaria0_ where rdbmsvaria0_.GUID_AND_INDEX=?
with 1 parameters begin parameter #1: 9C202AB9E8356288A9320C9C383A4D2F-11 :end parameter
java.lang.NullPointerException
        at org.apache.derby.impl.sql.GenericActivationHolder.execute(GenericActivationHolder.java:271)
        at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:368)
        at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1203)
        at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1652)
        at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(EmbedPreparedStatement.java:275)
        at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:186)
        at org.hibernate.loader.Loader.getResultSet(Loader.java:1787)
        at org.hibernate.loader.Loader.doQuery(Loader.java:674)
        at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
        at org.hibernate.loader.Loader.loadEntity(Loader.java:1860)
        at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:48)
        at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:42)
        at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3044)
        at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:395)
        at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:375)
        at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:139)
        at org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:179)
        at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:103)
        at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:878)
        at org.hibernate.impl.SessionImpl.get(SessionImpl.java:815)
        at org.hibernate.impl.SessionImpl.get(SessionImpl.java:808)
        at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:301)
        at $Proxy41.get(Unknown Source)
        at com.approuter.maestro.opera.rdbms.RdbmsContextHolder.getRdbmsVariable(RdbmsContextHolder.java:108)
        at com.approuter.maestro.opera.rdbms.RdbmsContextHolder.getVariable(RdbmsContextHolder.java:94)
        at com.approuter.maestro.vm.Frame.getParameter(Frame.java:218)
        at com.approuter.maestro.vm.Task.getParameter(Task.java:1267)
        at com.approuter.maestro.vm.CallContextImpl.setOutputParameter(CallContextImpl.java:195)
        at com.approuter.maestro.vm.CallContextImpl.getOutputParameterWriter(CallContextImpl.java:264)
        at com.approuter.maestro.sdk.mpi.DynamicExecutableActivity$3$1.getWriter(DynamicExecutableActivity.java:249)
        at com.approuter.module.xml.XmlSerializeTextActivity$XmlSerializeTextActivityInstance.serialize(XmlSerializeTextActivity.java:43)
        at sun.reflect.GeneratedMethodAccessor161.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at com.approuter.maestro.sdk.mpi.DynamicExecutableActivity.execute(DynamicExecutableActivity.java:332)
        at com.approuter.maestro.activities.Invoke.call(Invoke.java:199)
        at sun.reflect.GeneratedMethodAccessor157.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at com.approuter.maestro.activities.Instruction.call(Instruction.java:22)
        at com.approuter.maestro.vm.Program.call(Program.java:456)
        at com.approuter.maestro.vm.Task.run(Task.java:580)
        at com.approuter.maestro.vm.Task.run(Task.java:531)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:207)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
        at java.lang.Thread.run(Thread.java:619)
Cleanup action completed

Here is the relevant code from GenericActivationHolder.java

        // synchronized (ps)
        {
            /* Has the activation class changed? */
            if (gc != ps.getActivationClass())
            {

                // ensure the statement is valid by rePreparing it.
                ps.rePrepare(getLanguageConnectionContext());  // <-- line 260

                /*
                ** If we get here, it means the PreparedStatement has been
                ** recompiled.  Get a new Activation and check whether the
                ** parameters are compatible.  If so, transfer the parameters
                ** from the old Activation to the new one, and make that the
                ** current Activation.  If not, throw an exception.
                */
                GeneratedClass      newGC = ps.getActivationClass();

                BaseActivation      newAC = (BaseActivation) newGC.newInstance(lcc);  // <--
line 271

                DataTypeDescriptor[]    newParamTypes = ps.getParameterTypes();


As you can see, the activation class returned by the ExecPreparedStatement is null as of line
271, even after having called a rePrepare(...) on the prepared statement  (line 260).  This
is most likely due to a race condition.  Also note that the containing block was formerly
synchronized, but has since been commented out.  From browsing the source in previous versions,
the synchronized statement appears to have been commented out since before 10.0.2.1.  It appears
the fix is to reintroduce the synchronized block, or at least make the block inside the if
statement synchronized.

  was:
I have a stress test using Derby 10.3.1.4 which is executing the same PreparedStatement using
multiple threads concurrently and I consistently get the following NPE after several hours
of running:

2007-12-07 00:48:10.914 GMT Thread[pool-5-thread-25,5,main] (XID = 1219661), (SESSIONID =
377), (DATABASE = /usr/ironhide/var/db/opera/derby), (DRDAID = null), Failed Statement is:
select rdbmsvaria0_.GUID_AND_INDEX as GUID1_3_0_, rdbmsvaria0_.VALUE2 as VALUE2_3_0_, rdbmsvaria0_.HOLDER_GUID
as HOLDER3_3_0_, rdbmsvaria0_.VALUE_TYPE as VALUE4_3_0_, rdbmsvaria0_.VALUE_GUID as VALUE5_3_0_,
rdbmsvaria0_.DELETED as DELETED3_0_ from VARIABLE rdbmsvaria0_ where rdbmsvaria0_.GUID_AND_INDEX=?
with 1 parameters begin parameter #1: 9C202AB9E8356288A9320C9C383A4D2F-11 :end parameter
java.lang.NullPointerException
        at org.apache.derby.impl.sql.GenericActivationHolder.execute(GenericActivationHolder.java:271)
        at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:368)
        at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1203)
        at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1652)
        at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(EmbedPreparedStatement.java:275)
        at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:186)
        at org.hibernate.loader.Loader.getResultSet(Loader.java:1787)
        at org.hibernate.loader.Loader.doQuery(Loader.java:674)
        at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
        at org.hibernate.loader.Loader.loadEntity(Loader.java:1860)
        at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:48)
        at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:42)
        at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3044)
        at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:395)
        at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:375)
        at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:139)
        at org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:179)
        at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:103)
        at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:878)
        at org.hibernate.impl.SessionImpl.get(SessionImpl.java:815)
        at org.hibernate.impl.SessionImpl.get(SessionImpl.java:808)
        at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:301)
        at $Proxy41.get(Unknown Source)
        at com.approuter.maestro.opera.rdbms.RdbmsContextHolder.getRdbmsVariable(RdbmsContextHolder.java:108)
        at com.approuter.maestro.opera.rdbms.RdbmsContextHolder.getVariable(RdbmsContextHolder.java:94)
        at com.approuter.maestro.vm.Frame.getParameter(Frame.java:218)
        at com.approuter.maestro.vm.Task.getParameter(Task.java:1267)
        at com.approuter.maestro.vm.CallContextImpl.setOutputParameter(CallContextImpl.java:195)
        at com.approuter.maestro.vm.CallContextImpl.getOutputParameterWriter(CallContextImpl.java:264)
        at com.approuter.maestro.sdk.mpi.DynamicExecutableActivity$3$1.getWriter(DynamicExecutableActivity.java:249)
        at com.approuter.module.xml.XmlSerializeTextActivity$XmlSerializeTextActivityInstance.serialize(XmlSerializeTextActivity.java:43)
        at sun.reflect.GeneratedMethodAccessor161.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at com.approuter.maestro.sdk.mpi.DynamicExecutableActivity.execute(DynamicExecutableActivity.java:332)
        at com.approuter.maestro.activities.Invoke.call(Invoke.java:199)
        at sun.reflect.GeneratedMethodAccessor157.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at com.approuter.maestro.activities.Instruction.call(Instruction.java:22)
        at com.approuter.maestro.vm.Program.call(Program.java:456)
        at com.approuter.maestro.vm.Task.run(Task.java:580)
        at com.approuter.maestro.vm.Task.run(Task.java:531)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:207)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
        at java.lang.Thread.run(Thread.java:619)
Cleanup action completed

Here is the relevant code from GenericActivationHolder.java

        // synchronized (ps)
        {
            /* Has the activation class changed? */
            if (gc != ps.getActivationClass())
            {

                // ensure the statement is valid by rePreparing it.
                ps.rePrepare(getLanguageConnectionContext());

                /*
                ** If we get here, it means the PreparedStatement has been
                ** recompiled.  Get a new Activation and check whether the
                ** parameters are compatible.  If so, transfer the parameters
                ** from the old Activation to the new one, and make that the
                ** current Activation.  If not, throw an exception.
                */
                GeneratedClass      newGC = ps.getActivationClass();

                BaseActivation      newAC = (BaseActivation) newGC.newInstance(lcc);  // <--
line 271

                DataTypeDescriptor[]    newParamTypes = ps.getParameterTypes();


As you can see, the activation class returned by the ExecPreparedStatement is null as of line
271, even after having called a rePrepare(...) on the prepared statement  (line 269).  This
is most likely due to a race condition.  Also note that the containing block was formerly
synchronized, but has since been commented out.  From browsing the source in previous versions,
the synchronized statement appears to have been commented out since before 10.0.2.1.  It appears
the fix is to reintroduce the synchronized block, or at least make the block inside the if
statement synchronized.


> NullPointerException caused by race condition in GenericActivationHolder
> ------------------------------------------------------------------------
>
>                 Key: DERBY-3260
>                 URL: https://issues.apache.org/jira/browse/DERBY-3260
>             Project: Derby
>          Issue Type: Bug
>          Components: SQL
>    Affects Versions: 10.0.2.1, 10.1.1.0, 10.1.2.1, 10.1.3.1, 10.2.1.6, 10.2.2.0, 10.3.1.4
>            Reporter: Robert Yokota
>            Priority: Blocker
>
> I have a stress test using Derby 10.3.1.4 which is executing the same PreparedStatement
using multiple threads concurrently and I consistently get the following NPE after several
hours of running:
> 2007-12-07 00:48:10.914 GMT Thread[pool-5-thread-25,5,main] (XID = 1219661), (SESSIONID
= 377), (DATABASE = /usr/ironhide/var/db/opera/derby), (DRDAID = null), Failed Statement is:
select rdbmsvaria0_.GUID_AND_INDEX as GUID1_3_0_, rdbmsvaria0_.VALUE2 as VALUE2_3_0_, rdbmsvaria0_.HOLDER_GUID
as HOLDER3_3_0_, rdbmsvaria0_.VALUE_TYPE as VALUE4_3_0_, rdbmsvaria0_.VALUE_GUID as VALUE5_3_0_,
rdbmsvaria0_.DELETED as DELETED3_0_ from VARIABLE rdbmsvaria0_ where rdbmsvaria0_.GUID_AND_INDEX=?
with 1 parameters begin parameter #1: 9C202AB9E8356288A9320C9C383A4D2F-11 :end parameter
> java.lang.NullPointerException
>         at org.apache.derby.impl.sql.GenericActivationHolder.execute(GenericActivationHolder.java:271)
>         at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:368)
>         at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1203)
>         at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1652)
>         at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeQuery(EmbedPreparedStatement.java:275)
>         at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:186)
>         at org.hibernate.loader.Loader.getResultSet(Loader.java:1787)
>         at org.hibernate.loader.Loader.doQuery(Loader.java:674)
>         at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
>         at org.hibernate.loader.Loader.loadEntity(Loader.java:1860)
>         at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:48)
>         at org.hibernate.loader.entity.AbstractEntityLoader.load(AbstractEntityLoader.java:42)
>         at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:3044)
>         at org.hibernate.event.def.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:395)
>         at org.hibernate.event.def.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:375)
>         at org.hibernate.event.def.DefaultLoadEventListener.load(DefaultLoadEventListener.java:139)
>         at org.hibernate.event.def.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:179)
>         at org.hibernate.event.def.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:103)
>         at org.hibernate.impl.SessionImpl.fireLoad(SessionImpl.java:878)
>         at org.hibernate.impl.SessionImpl.get(SessionImpl.java:815)
>         at org.hibernate.impl.SessionImpl.get(SessionImpl.java:808)
>         at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown Source)
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>         at java.lang.reflect.Method.invoke(Method.java:597)
>         at org.hibernate.context.ThreadLocalSessionContext$TransactionProtectionWrapper.invoke(ThreadLocalSessionContext.java:301)
>         at $Proxy41.get(Unknown Source)
>         at com.approuter.maestro.opera.rdbms.RdbmsContextHolder.getRdbmsVariable(RdbmsContextHolder.java:108)
>         at com.approuter.maestro.opera.rdbms.RdbmsContextHolder.getVariable(RdbmsContextHolder.java:94)
>         at com.approuter.maestro.vm.Frame.getParameter(Frame.java:218)
>         at com.approuter.maestro.vm.Task.getParameter(Task.java:1267)
>         at com.approuter.maestro.vm.CallContextImpl.setOutputParameter(CallContextImpl.java:195)
>         at com.approuter.maestro.vm.CallContextImpl.getOutputParameterWriter(CallContextImpl.java:264)
>         at com.approuter.maestro.sdk.mpi.DynamicExecutableActivity$3$1.getWriter(DynamicExecutableActivity.java:249)
>         at com.approuter.module.xml.XmlSerializeTextActivity$XmlSerializeTextActivityInstance.serialize(XmlSerializeTextActivity.java:43)
>         at sun.reflect.GeneratedMethodAccessor161.invoke(Unknown Source)
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>         at java.lang.reflect.Method.invoke(Method.java:597)
>         at com.approuter.maestro.sdk.mpi.DynamicExecutableActivity.execute(DynamicExecutableActivity.java:332)
>         at com.approuter.maestro.activities.Invoke.call(Invoke.java:199)
>         at sun.reflect.GeneratedMethodAccessor157.invoke(Unknown Source)
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>         at java.lang.reflect.Method.invoke(Method.java:597)
>         at com.approuter.maestro.activities.Instruction.call(Instruction.java:22)
>         at com.approuter.maestro.vm.Program.call(Program.java:456)
>         at com.approuter.maestro.vm.Task.run(Task.java:580)
>         at com.approuter.maestro.vm.Task.run(Task.java:531)
>         at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
>         at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>         at java.util.concurrent.FutureTask.run(FutureTask.java:138)
>         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98)
>         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:207)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
>         at java.lang.Thread.run(Thread.java:619)
> Cleanup action completed
> Here is the relevant code from GenericActivationHolder.java
>         // synchronized (ps)
>         {
>             /* Has the activation class changed? */
>             if (gc != ps.getActivationClass())
>             {
>                 // ensure the statement is valid by rePreparing it.
>                 ps.rePrepare(getLanguageConnectionContext());  // <-- line 260
>                 /*
>                 ** If we get here, it means the PreparedStatement has been
>                 ** recompiled.  Get a new Activation and check whether the
>                 ** parameters are compatible.  If so, transfer the parameters
>                 ** from the old Activation to the new one, and make that the
>                 ** current Activation.  If not, throw an exception.
>                 */
>                 GeneratedClass      newGC = ps.getActivationClass();
>                 BaseActivation      newAC = (BaseActivation) newGC.newInstance(lcc);
 // <-- line 271
>                 DataTypeDescriptor[]    newParamTypes = ps.getParameterTypes();
> As you can see, the activation class returned by the ExecPreparedStatement is null as
of line 271, even after having called a rePrepare(...) on the prepared statement  (line 260).
 This is most likely due to a race condition.  Also note that the containing block was formerly
synchronized, but has since been commented out.  From browsing the source in previous versions,
the synchronized statement appears to have been commented out since before 10.0.2.1.  It appears
the fix is to reintroduce the synchronized block, or at least make the block inside the if
statement synchronized.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


Mime
View raw message