Re: [GENERAL] Mixed up protocol packets in server response?

Hello,
I have a quite weird problem. I described it in a mail to pgsql-general
quoted below, and quite obviously the general opinion is that the source is
on the application side, not server side. But the data is mixed up in
the jdbc driver, two method calls away from the standard library socket
code, so there is not much space for the application to mess it up.

There is the VisibleBufferedInputStream there. Could it do something
like this? Maybe if the connection was erroneously used from two
threads concurrently? The connections are pooled via commons-dbcp
BasicDataSource and queries are executed via Spring JdbcTemplate within
Spring-configured transactions. No passing connections by hand anywhere
and everything should be nicely thread-bound. Still, if not here, where
could it go wrong? Could someone possibly give some other suggestions?

On Wed, 1 Jun 2011 15:06:49 +0200, Michal Politowski wrote:
> I have an instance of what looks like a weird mixup of data returned by the server.
> This is observed in a Java application using the 9.0-801.jdbc4 JDBC driver
> connecting to an 8.3.4 server (yes, it's old) running on Solaris.
>
> The application hung waiting for the result of one
> select * from a_table where a_field = parameter;
>
> Looking at it with a debugger I see that:
> 1. it waits in:
> SocketInputStream.socketRead0(FileDescriptor, byte[], int, int, int) line: not available [native method]
> SocketInputStream.read(byte[], int, int) line: 129
> VisibleBufferedInputStream.read(byte[], int, int) line: 219
> PGStream.Receive(byte[], int, int) line: 460
> PGStream.ReceiveTupleV3() line: 365
> QueryExecutorImpl.processResults(ResultHandler, int) line: 1814
> QueryExecutorImpl.execute(Query, ParameterList, ResultHandler, int, int, int) line: 257
> Jdbc4PreparedStatement(AbstractJdbc2Statement).execute(Query, ParameterList, int) line: 500
> Jdbc4PreparedStatement(AbstractJdbc2Statement).executeWithFlags(int) line: 388
> Jdbc4PreparedStatement(AbstractJdbc2Statement).executeQuery() line: 273
> because it expects a field of size = 825767394 (l_size in ReceiveTupleV3)
> which is much more than the whole result should be.
>
> 2. then looking at the answer array in ReceiveTupleV3:
> A few first fields have the expected values,
> then answer[3] has the expected
> size but somewhere in the middle it changes from field 3 of the first row
> of the result to the middle of field 3 of the last row of the result.
> Then of course there are 4 bytes of this field that as a 32-bit integer
> have the value of 825767394.
> Then answer[4] obviously has 825767394 elements. And it continues with the
> field 3 of the last row and then it contains the 4-byte length and then
> value of the field 4 (last) of the last row of the result - so the end of a
> DataRow message.
> Then a CommandComplete message with the tag "SELECT",
> then a ReadyForQuery message with the status indicator "T".
> And then there is the rest of the field 3 of the first row, then length and
> value for the field 4 of the first row and then the DataRow messages for
> the following rows of the result. The last one up until the place where
> it got mixed up before.
>
> So it looks like the server wanted to send
> D row 1, D row 2, D row 3, D row 4, C SELECT, Z T
> but the application sees
> D ro, ow 4, C SELECT, Z T, w 1, D row 2, D row 3, D r
>
> What may be the cause of this weird problem? Is it some known or unknown bug in
> 8.3.4 or is the application/Java side more suspected?

--
Michał Politowski
Talking has been known to lead to communication if practiced carelessly.