You are viewing a plain text version of this content. The canonical link for it is here.
Posted to derby-dev@db.apache.org by Rick Hillegas <ri...@oracle.com> on 2010/04/26 22:00:44 UTC
instability in StreamingColumnTest
I saw the following error in StreamingColumnTest when run as part of the
full JUnit suite on the 10.6 branch. I did not see this error when I ran
that test standalone on that branch or on the trunk. Has anyone else
seen this instability?
1)
testDerby500_verifyVarcharStreams(org.apache.derbyTesting.functionTests.tests.store.StreamingColumnTest)junit.framework.ComparisonFailure:
Unexpected SQL state. expected:<X[N017]> but was:<X[J001]>
at
org.apache.derbyTesting.junit.BaseJDBCTestCase.assertSQLState(BaseJDBCTestCase.java:762)
at
org.apache.derbyTesting.junit.BaseJDBCTestCase.assertSQLState(BaseJDBCTestCase.java:797)
at
org.apache.derbyTesting.junit.BaseJDBCTestCase.assertSQLState(BaseJDBCTestCase.java:797)
at
org.apache.derbyTesting.junit.BaseJDBCTestCase.assertSQLState(BaseJDBCTestCase.java:811)
at
org.apache.derbyTesting.functionTests.tests.store.StreamingColumnTest.testDerby500_verifyVarcharStreams(StreamingColumnTest.java:1565)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at
org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:109)
at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
at junit.extensions.TestSetup.run(TestSetup.java:25)
at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
at junit.extensions.TestSetup.run(TestSetup.java:25)
at
org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)
at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
at junit.extensions.TestSetup.run(TestSetup.java:25)
at
org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)
at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
at junit.extensions.TestSetup.run(TestSetup.java:25)
at
org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)
at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
at junit.extensions.TestSetup.run(TestSetup.java:25)
at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
at junit.extensions.TestSetup.run(TestSetup.java:25)
Caused by: java.sql.SQLException: Java exception: 'Stream read error on
client side when transferring user data to server.: java.io.IOException'.
at
org.apache.derby.client.am.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:46)
at
org.apache.derby.client.am.SqlException.getSQLException(SqlException.java:358)
at
org.apache.derby.client.am.SqlException.getSQLException(SqlException.java:367)
at
org.apache.derby.client.am.SqlException.getSQLException(SqlException.java:367)
at
org.apache.derby.client.am.PreparedStatement.executeUpdate(PreparedStatement.java:403)
at
org.apache.derbyTesting.functionTests.tests.store.StreamingColumnTest.testDerby500_verifyVarcharStreams(StreamingColumnTest.java:1555)
... 53 more
Caused by: org.apache.derby.client.am.SqlException: Java exception:
'Stream read error on client side when transferring user data to
server.: java.io.IOException'.
at
org.apache.derby.client.am.Statement.completeExecute(Statement.java:1601)
at
org.apache.derby.client.net.NetStatementReply.parseEXCSQLSTTreply(NetStatementReply.java:322)
at
org.apache.derby.client.net.NetStatementReply.readExecute(NetStatementReply.java:71)
at
org.apache.derby.client.net.StatementReply.readExecute(StatementReply.java:55)
at
org.apache.derby.client.net.NetPreparedStatement.readExecute_(NetPreparedStatement.java:189)
at
org.apache.derby.client.am.PreparedStatement.readExecute(PreparedStatement.java:1797)
at
org.apache.derby.client.am.PreparedStatement.flowExecute(PreparedStatement.java:2094)
at
org.apache.derby.client.am.PreparedStatement.executeUpdateX(PreparedStatement.java:408)
at
org.apache.derby.client.am.PreparedStatement.executeUpdate(PreparedStatement.java:394)
... 54 more
Re: instability in StreamingColumnTest
Posted by Kristian Waagan <Kr...@Sun.COM>.
On 27.04.10 17:55, Rick Hillegas wrote:
> Thanks for investigating this, Kristian. Some comments inline...
>
> Kristian Waagan wrote:
>> On 26.04.10 22:00, Rick Hillegas wrote:
>>> I saw the following error in StreamingColumnTest when run as part of
>>> the full JUnit suite on the 10.6 branch. I did not see this error
>>> when I ran that test standalone on that branch or on the trunk. Has
>>> anyone else seen this instability?
>>
>> Hi Rick,
>>
>> I hadn't, but when I tried harder it manifested on my system as well.
>> The message in the stack trace below was introduced by DERBY-2017,
>> but that's a red herring.
>> Obviously the bug is timing dependent, and the issues at play here
>> are DERBY-4315, DERBY-4531 and DERBY-2017. The direct cause is
>> DERBY-4531, where the finalizer closes the character stream.
>> Depending on whether Java is able to run the finalizer, the stream
>> state differs (as observed by the Derby client driver):
>> o returns -1 on read, results in XN017 [1] (stream open, EOF)
>> o throws IOException ("Stream closed"), results in XN014 [2].
>>
>> Although XN017 is technically correct, one may argue that we could
>> introduce a special SQLState for the case where there is no data in
>> the user stream.
> The JDBC spec seems to me to be vague in this area. At this time, the
> major implementors may disagree on what the correct behavior is.
>> The simplest way to fix the instability is probably to fix DERBY-4531.
> Before adjusting Derby, it probably would be worthwhile to survey the
> JDBC expert group for their opinions about what is correct.
>> Opinions?
> In the meantime, I think that we should put some defensive code in the
> test in order to mask this non-deterministic behavior.
>>
>> Also note that the embedded Derby driver is able to "reuse streams"
>> for certain data types. This is due to the fact that the source is
>> represented as a DVD, in this case SQLVarchar, and the DVD will
>> materialize the stream the first time it is inserted. I don't think
>> this will work [in all cases] if the column is BLOB or CLOB.
>>
>> The question is whether we should disallow this usage or not. It can
>> be seen as a nice optimization, but to me this behavior isn't
>> intuitive. The same "optimization" can be achieved by using setString
>> instead of setXStream. The problem with keeping the current behavior
>> is that the code will work with embedded, but not with the client
>> driver.
> I'm afraid that I didn't follow this part of your analysis. Let me try
> to restate what I think you may have said. Consider the following
> example:
>
> ps.set???Stream( 1, userSuppliedStream, userSuppliedLength );
> ps.executeUpdate();
> ps.executeUpdate();
>
> The JDBC spec does not explain what should happen on the second
> update. Major implementors may handle the second update differently,
> particularly if the stream is actually longer than userSuppliedLength
> (I think there is wiggle room in the spec around whether the stream's
> length is EXACTLY or AT LEAST userSuppliedLength).
Hi Rick,
I think we are talking about three different issues here:
(a) What will the DBMS do if the stream is longer than
userSuppliedLength.
(b) What will the DBMS do if the same stream is reused for two or
more executeUpdate-calls.
(c) Should the DBMS close the stream after having read data from it.
Below we are talking about (b).
>
> Are you saying that Derby's behavior on the second update:
>
> 1) Differs depending on what the data type is
Yes (at least for the embedded driver, i.e. VARCHAR vs CLOB).
> 2) Differs depending on whether you are using the client or embedded
> driver
Yes.
> 3) Differs depending on what kind of stream is being used (binary,
> ascii, character)
Yes (only due to (c) that I know of currently).
> 4) Is non-deterministic
Well, throw GC/finalizers into the mix and we're getting close ;)
To avoid having the error pollute the test runs (too late for RC1
unfortunately), I'll make the test code accept both XN017 and XN014. The
test only expects that the second executeUpdate-call fails when running
with the client driver. I'll attach this workaround to DERBY-4531.
Regards,
--
Kristian
>
> Thanks,
> -Rick
>>
>>
>> Regards,
>
Re: instability in StreamingColumnTest
Posted by Rick Hillegas <ri...@oracle.com>.
Thanks for investigating this, Kristian. Some comments inline...
Kristian Waagan wrote:
> On 26.04.10 22:00, Rick Hillegas wrote:
>> I saw the following error in StreamingColumnTest when run as part of
>> the full JUnit suite on the 10.6 branch. I did not see this error
>> when I ran that test standalone on that branch or on the trunk. Has
>> anyone else seen this instability?
>
> Hi Rick,
>
> I hadn't, but when I tried harder it manifested on my system as well.
> The message in the stack trace below was introduced by DERBY-2017, but
> that's a red herring.
> Obviously the bug is timing dependent, and the issues at play here are
> DERBY-4315, DERBY-4531 and DERBY-2017. The direct cause is DERBY-4531,
> where the finalizer closes the character stream. Depending on whether
> Java is able to run the finalizer, the stream state differs (as
> observed by the Derby client driver):
> o returns -1 on read, results in XN017 [1] (stream open, EOF)
> o throws IOException ("Stream closed"), results in XN014 [2].
>
> Although XN017 is technically correct, one may argue that we could
> introduce a special SQLState for the case where there is no data in
> the user stream.
The JDBC spec seems to me to be vague in this area. At this time, the
major implementors may disagree on what the correct behavior is.
> The simplest way to fix the instability is probably to fix DERBY-4531.
Before adjusting Derby, it probably would be worthwhile to survey the
JDBC expert group for their opinions about what is correct.
> Opinions?
In the meantime, I think that we should put some defensive code in the
test in order to mask this non-deterministic behavior.
>
> Also note that the embedded Derby driver is able to "reuse streams"
> for certain data types. This is due to the fact that the source is
> represented as a DVD, in this case SQLVarchar, and the DVD will
> materialize the stream the first time it is inserted. I don't think
> this will work [in all cases] if the column is BLOB or CLOB.
>
> The question is whether we should disallow this usage or not. It can
> be seen as a nice optimization, but to me this behavior isn't
> intuitive. The same "optimization" can be achieved by using setString
> instead of setXStream. The problem with keeping the current behavior
> is that the code will work with embedded, but not with the client driver.
I'm afraid that I didn't follow this part of your analysis. Let me try
to restate what I think you may have said. Consider the following example:
ps.set???Stream( 1, userSuppliedStream, userSuppliedLength );
ps.executeUpdate();
ps.executeUpdate();
The JDBC spec does not explain what should happen on the second update.
Major implementors may handle the second update differently,
particularly if the stream is actually longer than userSuppliedLength (I
think there is wiggle room in the spec around whether the stream's
length is EXACTLY or AT LEAST userSuppliedLength).
Are you saying that Derby's behavior on the second update:
1) Differs depending on what the data type is
2) Differs depending on whether you are using the client or embedded driver
3) Differs depending on what kind of stream is being used (binary,
ascii, character)
4) Is non-deterministic
Thanks,
-Rick
>
>
> Regards,
Re: instability in StreamingColumnTest
Posted by Kristian Waagan <Kr...@Sun.COM>.
On 26.04.10 22:00, Rick Hillegas wrote:
> I saw the following error in StreamingColumnTest when run as part of
> the full JUnit suite on the 10.6 branch. I did not see this error when
> I ran that test standalone on that branch or on the trunk. Has anyone
> else seen this instability?
Hi Rick,
I hadn't, but when I tried harder it manifested on my system as well.
The message in the stack trace below was introduced by DERBY-2017, but
that's a red herring.
Obviously the bug is timing dependent, and the issues at play here are
DERBY-4315, DERBY-4531 and DERBY-2017. The direct cause is DERBY-4531,
where the finalizer closes the character stream. Depending on whether
Java is able to run the finalizer, the stream state differs (as observed
by the Derby client driver):
o returns -1 on read, results in XN017 [1] (stream open, EOF)
o throws IOException ("Stream closed"), results in XN014 [2].
Although XN017 is technically correct, one may argue that we could
introduce a special SQLState for the case where there is no data in the
user stream.
The simplest way to fix the instability is probably to fix DERBY-4531.
Opinions?
Also note that the embedded Derby driver is able to "reuse streams" for
certain data types. This is due to the fact that the source is
represented as a DVD, in this case SQLVarchar, and the DVD will
materialize the stream the first time it is inserted. I don't think this
will work [in all cases] if the column is BLOB or CLOB.
The question is whether we should disallow this usage or not. It can be
seen as a nice optimization, but to me this behavior isn't intuitive.
The same "optimization" can be achieved by using setString instead of
setXStream. The problem with keeping the current behavior is that the
code will work with embedded, but not with the client driver.
Regards,
--
Kristian
[1] XN017, NET_PREMATURE_EOS: Network protocol error: end of stream
prematurely reached, parameter #{0}. Remaining data has been padded
with 0x0.
[2] XN014, NET_IOEXCEPTION_ON_READ: Network protocol error: encountered
an IOException, parameter #{0}. Remaining data has been padded with
0x0. Message: {1}.
>
> 1)
> testDerby500_verifyVarcharStreams(org.apache.derbyTesting.functionTests.tests.store.StreamingColumnTest)junit.framework.ComparisonFailure:
> Unexpected SQL state. expected:<X[N017]> but was:<X[J001]>
> at
> org.apache.derbyTesting.junit.BaseJDBCTestCase.assertSQLState(BaseJDBCTestCase.java:762)
>
> at
> org.apache.derbyTesting.junit.BaseJDBCTestCase.assertSQLState(BaseJDBCTestCase.java:797)
>
> at
> org.apache.derbyTesting.junit.BaseJDBCTestCase.assertSQLState(BaseJDBCTestCase.java:797)
>
> at
> org.apache.derbyTesting.junit.BaseJDBCTestCase.assertSQLState(BaseJDBCTestCase.java:811)
>
> at
> org.apache.derbyTesting.functionTests.tests.store.StreamingColumnTest.testDerby500_verifyVarcharStreams(StreamingColumnTest.java:1565)
>
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
>
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>
> at
> org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:109)
> at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
> at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
> at junit.extensions.TestSetup.run(TestSetup.java:25)
> at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
> at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
> at junit.extensions.TestSetup.run(TestSetup.java:25)
> at
> org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)
> at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
> at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
> at junit.extensions.TestSetup.run(TestSetup.java:25)
> at
> org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)
> at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
> at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
> at junit.extensions.TestSetup.run(TestSetup.java:25)
> at
> org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)
> at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
> at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
> at junit.extensions.TestSetup.run(TestSetup.java:25)
> at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
> at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
> at junit.extensions.TestSetup.run(TestSetup.java:25)
> Caused by: java.sql.SQLException: Java exception: 'Stream read error
> on client side when transferring user data to server.:
> java.io.IOException'.
> at
> org.apache.derby.client.am.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:46)
>
> at
> org.apache.derby.client.am.SqlException.getSQLException(SqlException.java:358)
>
> at
> org.apache.derby.client.am.SqlException.getSQLException(SqlException.java:367)
>
> at
> org.apache.derby.client.am.SqlException.getSQLException(SqlException.java:367)
>
> at
> org.apache.derby.client.am.PreparedStatement.executeUpdate(PreparedStatement.java:403)
>
> at
> org.apache.derbyTesting.functionTests.tests.store.StreamingColumnTest.testDerby500_verifyVarcharStreams(StreamingColumnTest.java:1555)
>
> ... 53 more
> Caused by: org.apache.derby.client.am.SqlException: Java exception:
> 'Stream read error on client side when transferring user data to
> server.: java.io.IOException'.
> at
> org.apache.derby.client.am.Statement.completeExecute(Statement.java:1601)
> at
> org.apache.derby.client.net.NetStatementReply.parseEXCSQLSTTreply(NetStatementReply.java:322)
>
> at
> org.apache.derby.client.net.NetStatementReply.readExecute(NetStatementReply.java:71)
>
> at
> org.apache.derby.client.net.StatementReply.readExecute(StatementReply.java:55)
>
> at
> org.apache.derby.client.net.NetPreparedStatement.readExecute_(NetPreparedStatement.java:189)
>
> at
> org.apache.derby.client.am.PreparedStatement.readExecute(PreparedStatement.java:1797)
>
> at
> org.apache.derby.client.am.PreparedStatement.flowExecute(PreparedStatement.java:2094)
>
> at
> org.apache.derby.client.am.PreparedStatement.executeUpdateX(PreparedStatement.java:408)
>
> at
> org.apache.derby.client.am.PreparedStatement.executeUpdate(PreparedStatement.java:394)
>
> ... 54 more
>