SEO

People, I am having a very anoying problem:

I am issuing this:

boolean result = false;
Statement stm = null;
ResultSet rs = null;
try
{
stm = conn.createStatement( ResultSet.TYPE_FORWARD_ONLY,
ResultSet.CONCUR_READ_ONLY );
stm.setQueryTimeout( timeout );
rs = stm.executeQuery( sql ); <- the proccess is stopped here
for more than half an hour
result = rs.next();
}
finally
{
DbUtils.closeQuietly( rs );
DbUtils.closeQuietly( stm );
}
return result;


sql is a simple select that returns one row (if I take it and send to pgsql
it works fine)
timeout = 120 (seconds) / I am using a DBCP pool / I use one or more
connection per thread (I get it inside the method and release inside the
method)

If I get my debbuger and interrupt the thread I see it stopped in some point
of execution of stm.executeQuery (it seems to be waitng a response from the
postgres server) but at the same time I go to the server and does not find
the query itself runnning.

It seems to me that for some (weird) reason, the query timeout is bein
achieved without throwing any error or the postgresql driver detecting that.


This is some know issue?
It is possible that the backend is cancelling the connection by timeout and
the driver does not notice and continues waiting for it?

the driver I am using is postgresql-8.2dev-503.jdbc3.jar (and it happens the
same thing with the 8.0 driver)

and the stack trace of one of such locked proccess:

Thread [zzzzzzz:12] (Suspended)
SocketInputStream.socketRead0(FileDescriptor, byte[], int, int, int)
line: not available [native method]
SocketInputStream.read(byte[], int, int) line: not available
BufferedInputStream.fill() line: not available
BufferedInputStream.read() line: not available
PGStream.ReceiveChar() line: 256
QueryExecutorImpl.processResults(ResultHandler, int) line: 1164
QueryExecutorImpl.execute(Query, ParameterList, ResultHandler, int, int,
int) line: 190
Jdbc3Statement(AbstractJdbc2Statement).execute(Que ry, ParameterList,
int) line: 452
Jdbc3Statement(AbstractJdbc2Statement).executeWith Flags(String, int)
line: 340
Jdbc3Statement(AbstractJdbc2Statement).executeQuer y(String) line: 239
DelegatingStatement.executeQuery(String) line: 205
xxxx() line: 580 <- this is the line in the code I sent.
xxxx(int) line: 504
xxxx(int) line: 523
xxxx() line: 156
NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not
available [native method]
NativeMethodAccessorImpl.invoke(Object, Object[]) line: not available
DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: not
available
Method.invoke(Object, Object...) line: not available
ScheduleTaskRunner.run() line: 139
Thread.run() line: not available

Has anyone seen this kind of situation before?

It could possibly be a bug in the driver, but much more likely it's just
the server waiting on some normal condition.

What exactly is the query in question? Are you running with autocommit
on or off?

-- Mark Lewis

On Tue, 2006-07-11 at 13:29 -0300, Lucas Sousa wrote:
> People, I am having a very anoying problem:
>
> I am issuing this:
>
> boolean result = false;
> Statement stm = null;
> ResultSet rs = null;
> try
> {
> stm = conn.createStatement( ResultSet.TYPE_FORWARD_ONLY,
> ResultSet.CONCUR_READ_ONLY );
> stm.setQueryTimeout( timeout );
> rs = stm.executeQuery( sql ); <- the proccess is stopped
> here for more than half an hour
> result = rs.next();
> }
> finally
> {
> DbUtils.closeQuietly( rs );
> DbUtils.closeQuietly( stm );
> }
> return result;
>
>
> sql is a simple select that returns one row (if I take it and send to
> pgsql it works fine)
> timeout = 120 (seconds) / I am using a DBCP pool / I use one or more
> connection per thread (I get it inside the method and release inside
> the method)
>
> If I get my debbuger and interrupt the thread I see it stopped in some
> point of execution of stm.executeQuery (it seems to be waitng a
> response from the postgres server) but at the same time I go to the
> server and does not find the query itself runnning.
>
> It seems to me that for some (weird) reason, the query timeout is bein
> achieved without throwing any error or the postgresql driver detecting
> that.
>
> This is some know issue?
> It is possible that the backend is cancelling the connection by
> timeout and the driver does not notice and continues waiting for it?
>
> the driver I am using is postgresql-8.2dev-503.jdbc3.jar (and it
> happens the same thing with the 8.0 driver)
>
> and the stack trace of one of such locked proccess:
>
> Thread [zzzzzzz:12] (Suspended)
> SocketInputStream.socketRead0(FileDescriptor, byte[], int, int,
> int) line: not available [native method]
> SocketInputStream.read(byte[], int, int) line: not available
> BufferedInputStream.fill() line: not available
> BufferedInputStream.read() line: not available
> PGStream.ReceiveChar() line: 256
> QueryExecutorImpl.processResults(ResultHandler, int) line: 1164
> QueryExecutorImpl.execute(Query, ParameterList, ResultHandler,
> int, int, int) line: 190
> Jdbc3Statement(AbstractJdbc2Statement).execute(Que ry,
> ParameterList, int) line: 452
> Jdbc3Statement(AbstractJdbc2Statement).executeWith Flags(String,
> int) line: 340
> Jdbc3Statement(AbstractJdbc2Statement).executeQuer y(String) line:
> 239
> DelegatingStatement.executeQuery(String) line: 205
> xxxx() line: 580 <- this is the line in the code I sent.
> xxxx(int) line: 504
> xxxx(int) line: 523
> xxxx() line: 156
> NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line:
> not available [native method]
> NativeMethodAccessorImpl.invoke(Object, Object[]) line: not
> available
> DelegatingMethodAccessorImpl.invoke (Object, Object[]) line: not
> available
> Method.invoke(Object, Object...) line: not available
> ScheduleTaskRunner.run() line: 139
> Thread.run() line: not available
>
> Has anyone seen this kind of situation before?
>
>

---------------------------(end of broadcast)---------------------------
TIP 9: In versions below 8.0, the planner will ignore your desire to
choose an index scan if your joining column's datatypes do not
match

Please remember to CC the list on any emails. This one is beyond my
skill, so hopefully somebody else can help you out.

-- Mark Lewis

On Tue, 2006-07-11 at 15:23 -0300, Lucas Sousa wrote:
> I think that has something to do with the PhantomReferences
>
> The problem seem to be related with the garbage collector...
>
> My application force the garbage collector to run periodically. I
> stopped that for testing purposes and that locking problem does not
> happened for the last hour and a half.
>
>
>
> On 7/11/06, Lucas Sousa <lucas75@gmail.com> wrote:
> autocommit is off
>
> the query is a plain "select 1 from tb_1 where a=b and b=c and
> c=d"
>
> where a=b and b=c and c=d is the primary key of the table
> it should not last more than millisseconds (in fact doesn't)
> but sometimes one of the threads that is executing that sql
> seems to stop rigth there waiting for the result. That is why
> I set the queryTimeout for 120 seconds, but seems that the
> query timeout is not working at all.
>
>
>
> On 7/11/06, Mark Lewis <mark.lewis@mir3.com> wrote:
> It could possibly be a bug in the driver, but much
> more likely it's just
> the server waiting on some normal condition.
>
> What exactly is the query in question? Are you
> running with autocommit
> on or off?
>
> -- Mark Lewis
>
> On Tue, 2006-07-11 at 13:29 -0300, Lucas Sousa wrote:
> > People, I am having a very anoying problem:
> >
> > I am issuing this:
> >
> > boolean result = false;
> > Statement stm = null;
> > ResultSet rs = null;
> > try
> > {
> > stm = conn.createStatement
> ( ResultSet.TYPE_FORWARD_ONLY,
> > ResultSet.CONCUR_READ_ONLY );
> > stm.setQueryTimeout ( timeout );
> > rs = stm.executeQuery( sql ); <- the
> proccess is stopped
> > here for more than half an hour
> > result = rs.next();
> > }
> > finally
> > {
> > DbUtils.closeQuietly( rs );
> > DbUtils.closeQuietly( stm );
> > }
> > return result;
> >
> >
> > sql is a simple select that returns one row (if I
> take it and send to
> > pgsql it works fine)
> > timeout = 120 (seconds) / I am using a DBCP pool / I
> use one or more
> > connection per thread (I get it inside the method
> and release inside
> > the method)
> >
> > If I get my debbuger and interrupt the thread I see
> it stopped in some
> > point of execution of stm.executeQuery (it seems to
> be waitng a
> > response from the postgres server) but at the same
> time I go to the
> > server and does not find the query itself runnning.
> >
> > It seems to me that for some (weird) reason, the
> query timeout is bein
> > achieved without throwing any error or the
> postgresql driver detecting
> > that.
> >
> > This is some know issue?
> > It is possible that the backend is cancelling the
> connection by
> > timeout and the driver does not notice and continues
> waiting for it?
> >
> > the driver I am using is
> postgresql-8.2dev-503.jdbc3.jar (and it
> > happens the same thing with the 8.0 driver)
> >
> > and the stack trace of one of such locked proccess:
> >
> > Thread [zzzzzzz:12] (Suspended)
> > SocketInputStream.socketRead0(FileDescriptor,
> byte[], int, int,
> > int) line: not available [native method]
> > SocketInputStream.read(byte[], int, int) line:
> not available
> > BufferedInputStream.fill () line: not available
> > BufferedInputStream.read() line: not available
> > PGStream.ReceiveChar() line: 256
> > QueryExecutorImpl.processResults(ResultHandler,
> int) line: 1164
> > QueryExecutorImpl.execute (Query, ParameterList,
> ResultHandler,
> > int, int, int) line: 190
> > Jdbc3Statement(AbstractJdbc2Statement).execute
> (Query,
> > ParameterList, int) line: 452
> > Jdbc3Statement
> (AbstractJdbc2Statement).executeWithFlags(String,
> > int) line: 340
> > Jdbc3Statement
> (AbstractJdbc2Statement).executeQuery(String) line:
> > 239
> > DelegatingStatement.executeQuery(String) line:
> 205
> > xxxx() line: 580 <- this is the line in the code
> I sent.
> > xxxx(int) line: 504
> > xxxx(int) line: 523
> > xxxx() line: 156
> > NativeMethodAccessorImpl.invoke0(Method, Object,
> Object[]) line:
> > not available [native method]
> > NativeMethodAccessorImpl.invoke(Object, Object
> []) line: not
> > available
> > DelegatingMethodAccessorImpl.invoke (Object,
> Object[]) line: not
> > available
> > Method.invoke(Object, Object...) line: not
> available
> > ScheduleTaskRunner.run() line: 139
> > Thread.run() line: not available
> >
> > Has anyone seen this kind of situation before?
> >
> >
>
>
>

---------------------------(end of broadcast)---------------------------
TIP 6: explain analyze is your friend

Lucas Sousa wrote:

> stm.setQueryTimeout( timeout );

> It seems to me that for some (weird) reason, the query timeout is bein
> achieved without throwing any error or the postgresql driver detecting
> that.
>
> This is some know issue?

Unfortunately setQueryTimeout() is currently a no-op. As a workaround,
set the server's statement_timeout variable.

> Thread [zzzzzzz:12] (Suspended)
> SocketInputStream.socketRead0(FileDescriptor, byte[], int, int, int)
> line: not available [native method]
> SocketInputStream.read(byte[], int, int) line: not available
> BufferedInputStream.fill() line: not available
> BufferedInputStream.read() line: not available
> PGStream.ReceiveChar() line: 256
> QueryExecutorImpl.processResults(ResultHandler, int) line: 1164

The driver is waiting for results from the server. Either the query is
still running or something has got confused about what's happening at
the protocol level.

Can you reproduce this with loglevel=2 set (as a URL parameter, see the
driver docs)? Or a tcpdump/snoop/ethereal capture of the connection with
the server when it gets stuck would also be useful. Also, if you could
attach to the corresponding backend via gdb or similar and get a stack
trace that may help.

-O

---------------------------(end of broadcast)---------------------------
TIP 6: explain analyze is your friend

I am debugging the driver myself, I am looking into the PhantomReferences
that I think may be the cause of the problem (the problem seems to me
loosely related with the garbage collector frequency)

If I do the "set statement_timeout = 60000" on that connection I suppose
that after I release this connection back to the pool and another thread
fetches it the statement timeout will remain set ... is it not?

But it is good to know that I am not crazy....


On 7/12/06, Oliver Jowett <oliver@opencloud.com> wrote:
>
> Lucas Sousa wrote:
>
> > stm.setQueryTimeout( timeout );
>
> > It seems to me that for some (weird) reason, the query timeout is bein
> > achieved without throwing any error or the postgresql driver detecting
> > that.
> >
> > This is some know issue?
>
> Unfortunately setQueryTimeout() is currently a no-op. As a workaround,
> set the server's statement_timeout variable.
>
> > Thread [zzzzzzz:12] (Suspended)
> > SocketInputStream.socketRead0(FileDescriptor, byte[], int, int, int)
> > line: not available [native method]
> > SocketInputStream.read(byte[], int, int) line: not available
> > BufferedInputStream.fill() line: not available
> > BufferedInputStream.read() line: not available
> > PGStream.ReceiveChar() line: 256
> > QueryExecutorImpl.processResults(ResultHandler, int) line: 1164
>
> The driver is waiting for results from the server. Either the query is
> still running or something has got confused about what's happening at
> the protocol level.
>
> Can you reproduce this with loglevel=2 set (as a URL parameter, see the
> driver docs)? Or a tcpdump/snoop/ethereal capture of the connection with
> the server when it gets stuck would also be useful. Also, if you could
> attach to the corresponding backend via gdb or similar and get a stack
> trace that may help.
>
> -O
>

Lucas Sousa wrote:
> I am debugging the driver myself, I am looking into the
> PhantomReferences that I think may be the cause of the problem (the
> problem seems to me loosely related with the garbage collector frequency)

Well, if you collect a trace of the communication between driver and
server as I suggested, it will let you work out whether it really is the
driver at fault, and what it did around the time of the failure.

The PhantomReference stuff is used to free up old server-side prepared
statements where the corresponding Java objects have gone away. In
theory it shouldn't affect query execution..

> If I do the "set statement_timeout = 60000" on that connection I suppose
> that after I release this connection back to the pool and another thread
> fetches it the statement timeout will remain set ... is it not?

That's right. You could always explicitly set statement_timeout after
getting a new connection from the pool, I suppose.

-O

---------------------------(end of broadcast)---------------------------
TIP 5: don't forget to increase your free space map settings