Thread: executeQuery and busy waiting
I'm working on a project with Postgresql and I'm running into a strange problem. I have a Java Program running on the Database server that periodicly connects to the Database and runs a pl/pgsql function. This function should run fairly fast, but could take several minutes based on the load of the server and amount of information it needs to process. Running the function from psql takes 40 seconds under no load and minimal data, but when I run the function from java using JDBC it takes 20-30 minutes. Checking top, this is a Linux system, I see that the java program takes up 99% of the CPU when it's running this function through executeQuery. Is executeQuery() doing a busy wait for the data from postgres? It seems a bit absurd that the executeQuery method would hijack 99% of the CPU waiting for results and slowing everything else on the system down. The second problem I am noticing is that if I move the java program to another machine, to keep java from stealing all the CPU cycles, the function still takes 20-30 minutes to run through java, but only takes 40 seconds to run through psql. What's the deal? Any help would be appreciated. Garrick Dasbach Software Developer MusicRebellion.com, Inc. Garrick@musicrebellion.com
Garrick, It would help if you posted a small program to replicate the problem. Dave On Fri, 2003-06-27 at 14:44, Garrick Dasbach wrote: > I'm working on a project with Postgresql and I'm running into a strange > problem. > > I have a Java Program running on the Database server that periodicly > connects to the Database and runs a pl/pgsql function. This function > should run fairly fast, but could take several minutes based on the load > of the server and amount of information it needs to process. > > Running the function from psql takes 40 seconds under no load and > minimal data, but when I run the function from java using JDBC it takes > 20-30 minutes. > > Checking top, this is a Linux system, I see that the java program takes > up 99% of the CPU when it's running this function through executeQuery. > Is executeQuery() doing a busy wait for the data from postgres? It > seems a bit absurd that the executeQuery method would hijack 99% of the > CPU waiting for results and slowing everything else on the system down. > > The second problem I am noticing is that if I move the java program to > another machine, to keep java from stealing all the CPU cycles, the > function still takes 20-30 minutes to run through java, but only takes > 40 seconds to run through psql. What's the deal? > > Any help would be appreciated. > > Garrick Dasbach > > Software Developer > MusicRebellion.com, Inc. > Garrick@musicrebellion.com > > > ---------------------------(end of broadcast)--------------------------- > TIP 9: the planner will ignore your desire to choose an index scan if your > joining column's datatypes do not match > -- Dave Cramer <Dave@micro-automation.net>
It's about as simple a JDBC program as you can get. Source included
below, minus company info ofcourse.
public static void main(String[] args) {
Connection conn = null;
Statement stmt = null;
ResultSet rs = null;
try{
Class.forName("org.postgresql.Driver");
conn = DriverManager.getConnection("jdbc:postgresql://server_ip/db_name", "user", "password");
stmt = conn.createStatement();
rs = stmt.executeQuery("select myFunction(2)");
if(rs.next()){
System.out.println("Function Execution Successfull.");
}
} catch (Exception e){
e.printStackTrace();
} finally {
try{ rs.close(); } catch (Exception e){}
try{ stmt.close(); } catch (Exception e){}
try{ conn.close(); } catch (Exception e){}
}
}
Garick Dasbach
On Fri, 2003-06-27 at 13:53, Dave Cramer wrote:
> Garrick,
>
> It would help if you posted a small program to replicate the problem.
>
> Dave
> On Fri, 2003-06-27 at 14:44, Garrick Dasbach wrote:
> > I'm working on a project with Postgresql and I'm running into a strange
> > problem.
> >
> > I have a Java Program running on the Database server that periodicly
> > connects to the Database and runs a pl/pgsql function. This function
> > should run fairly fast, but could take several minutes based on the load
> > of the server and amount of information it needs to process.
> >
> > Running the function from psql takes 40 seconds under no load and
> > minimal data, but when I run the function from java using JDBC it takes
> > 20-30 minutes.
> >
> > Checking top, this is a Linux system, I see that the java program takes
> > up 99% of the CPU when it's running this function through executeQuery.
> > Is executeQuery() doing a busy wait for the data from postgres? It
> > seems a bit absurd that the executeQuery method would hijack 99% of the
> > CPU waiting for results and slowing everything else on the system down.
> >
> > The second problem I am noticing is that if I move the java program to
> > another machine, to keep java from stealing all the CPU cycles, the
> > function still takes 20-30 minutes to run through java, but only takes
> > 40 seconds to run through psql. What's the deal?
> >
> > Any help would be appreciated.
> >
> > Garrick Dasbach
> >
> > Software Developer
> > MusicRebellion.com, Inc.
> > Garrick@musicrebellion.com
> >
> >
> > ---------------------------(end of broadcast)---------------------------
> > TIP 9: the planner will ignore your desire to choose an index scan if your
> > joining column's datatypes do not match
> >
> --
> Dave Cramer <Dave@micro-automation.net>
>
>
> ---------------------------(end of broadcast)---------------------------
> TIP 1: subscribe and unsubscribe commands go to majordomo@postgresql.org
Unfortunately, I can't release the source for the function due to IP
concerns. However considering the function runs in about 40 seconds
through the psql terminal, should it matter what the function does since
it should run in the same amount of time through JDBC?
Garrick
On Fri, 2003-06-27 at 14:02, Dave Cramer wrote:
> Garrick,
>
> Given that nextval('sequence') is a function and I do those all the
> time, I would probably need to see the function.
>
> Dave
> On Fri, 2003-06-27 at 14:58, Garrick Dasbach wrote:
> > It's about as simple a JDBC program as you can get. Source included
> > below, minus company info ofcourse.
> >
> > public static void main(String[] args) {
> > Connection conn = null;
> > Statement stmt = null;
> > ResultSet rs = null;
> > try{
> > Class.forName("org.postgresql.Driver");
> > conn = DriverManager.getConnection("jdbc:postgresql://server_ip/db_name", "user", "password");
> > stmt = conn.createStatement();
> > rs = stmt.executeQuery("select myFunction(2)");
> > if(rs.next()){
> > System.out.println("Function Execution Successfull.");
> > }
> > } catch (Exception e){
> > e.printStackTrace();
> > } finally {
> > try{ rs.close(); } catch (Exception e){}
> > try{ stmt.close(); } catch (Exception e){}
> > try{ conn.close(); } catch (Exception e){}
> > }
> > }
> >
> > Garick Dasbach
> >
> >
> > On Fri, 2003-06-27 at 13:53, Dave Cramer wrote:
> > > Garrick,
> > >
> > > It would help if you posted a small program to replicate the problem.
> > >
> > > Dave
> > > On Fri, 2003-06-27 at 14:44, Garrick Dasbach wrote:
> > > > I'm working on a project with Postgresql and I'm running into a strange
> > > > problem.
> > > >
> > > > I have a Java Program running on the Database server that periodicly
> > > > connects to the Database and runs a pl/pgsql function. This function
> > > > should run fairly fast, but could take several minutes based on the load
> > > > of the server and amount of information it needs to process.
> > > >
> > > > Running the function from psql takes 40 seconds under no load and
> > > > minimal data, but when I run the function from java using JDBC it takes
> > > > 20-30 minutes.
> > > >
> > > > Checking top, this is a Linux system, I see that the java program takes
> > > > up 99% of the CPU when it's running this function through executeQuery.
> > > > Is executeQuery() doing a busy wait for the data from postgres? It
> > > > seems a bit absurd that the executeQuery method would hijack 99% of the
> > > > CPU waiting for results and slowing everything else on the system down.
> > > >
> > > > The second problem I am noticing is that if I move the java program to
> > > > another machine, to keep java from stealing all the CPU cycles, the
> > > > function still takes 20-30 minutes to run through java, but only takes
> > > > 40 seconds to run through psql. What's the deal?
> > > >
> > > > Any help would be appreciated.
> > > >
> > > > Garrick Dasbach
> > > >
> > > > Software Developer
> > > > MusicRebellion.com, Inc.
> > > > Garrick@musicrebellion.com
> > > >
> > > >
> > > > ---------------------------(end of broadcast)---------------------------
> > > > TIP 9: the planner will ignore your desire to choose an index scan if your
> > > > joining column's datatypes do not match
> > > >
> > > --
> > > Dave Cramer <Dave@micro-automation.net>
> > >
> > >
> > > ---------------------------(end of broadcast)---------------------------
> > > TIP 1: subscribe and unsubscribe commands go to majordomo@postgresql.org
> >
> >
> --
> Dave Cramer <Dave@micro-automation.net>
>
Garrick,
You are correct, it should run in the same time over the jdbc
connection.
Obviously there is a problem somewhere, but given that something like
select nextval(...) or select now() both call functions and return
quickly.
I am at a loss to explain the behaviour.
If I can't see it on my machine, how can I fix it?
Dave
On Fri, 2003-06-27 at 15:10, Garrick Dasbach wrote:
> Unfortunately, I can't release the source for the function due to IP
> concerns. However considering the function runs in about 40 seconds
> through the psql terminal, should it matter what the function does since
> it should run in the same amount of time through JDBC?
>
> Garrick
>
>
> On Fri, 2003-06-27 at 14:02, Dave Cramer wrote:
> > Garrick,
> >
> > Given that nextval('sequence') is a function and I do those all the
> > time, I would probably need to see the function.
> >
> > Dave
> > On Fri, 2003-06-27 at 14:58, Garrick Dasbach wrote:
> > > It's about as simple a JDBC program as you can get. Source included
> > > below, minus company info ofcourse.
> > >
> > > public static void main(String[] args) {
> > > Connection conn = null;
> > > Statement stmt = null;
> > > ResultSet rs = null;
> > > try{
> > > Class.forName("org.postgresql.Driver");
> > > conn = DriverManager.getConnection("jdbc:postgresql://server_ip/db_name", "user", "password");
> > > stmt = conn.createStatement();
> > > rs = stmt.executeQuery("select myFunction(2)");
> > > if(rs.next()){
> > > System.out.println("Function Execution Successfull.");
> > > }
> > > } catch (Exception e){
> > > e.printStackTrace();
> > > } finally {
> > > try{ rs.close(); } catch (Exception e){}
> > > try{ stmt.close(); } catch (Exception e){}
> > > try{ conn.close(); } catch (Exception e){}
> > > }
> > > }
> > >
> > > Garick Dasbach
> > >
> > >
> > > On Fri, 2003-06-27 at 13:53, Dave Cramer wrote:
> > > > Garrick,
> > > >
> > > > It would help if you posted a small program to replicate the problem.
> > > >
> > > > Dave
> > > > On Fri, 2003-06-27 at 14:44, Garrick Dasbach wrote:
> > > > > I'm working on a project with Postgresql and I'm running into a strange
> > > > > problem.
> > > > >
> > > > > I have a Java Program running on the Database server that periodicly
> > > > > connects to the Database and runs a pl/pgsql function. This function
> > > > > should run fairly fast, but could take several minutes based on the load
> > > > > of the server and amount of information it needs to process.
> > > > >
> > > > > Running the function from psql takes 40 seconds under no load and
> > > > > minimal data, but when I run the function from java using JDBC it takes
> > > > > 20-30 minutes.
> > > > >
> > > > > Checking top, this is a Linux system, I see that the java program takes
> > > > > up 99% of the CPU when it's running this function through executeQuery.
> > > > > Is executeQuery() doing a busy wait for the data from postgres? It
> > > > > seems a bit absurd that the executeQuery method would hijack 99% of the
> > > > > CPU waiting for results and slowing everything else on the system down.
> > > > >
> > > > > The second problem I am noticing is that if I move the java program to
> > > > > another machine, to keep java from stealing all the CPU cycles, the
> > > > > function still takes 20-30 minutes to run through java, but only takes
> > > > > 40 seconds to run through psql. What's the deal?
> > > > >
> > > > > Any help would be appreciated.
> > > > >
> > > > > Garrick Dasbach
> > > > >
> > > > > Software Developer
> > > > > MusicRebellion.com, Inc.
> > > > > Garrick@musicrebellion.com
> > > > >
> > > > >
> > > > > ---------------------------(end of broadcast)---------------------------
> > > > > TIP 9: the planner will ignore your desire to choose an index scan if your
> > > > > joining column's datatypes do not match
> > > > >
> > > > --
> > > > Dave Cramer <Dave@micro-automation.net>
> > > >
> > > >
> > > > ---------------------------(end of broadcast)---------------------------
> > > > TIP 1: subscribe and unsubscribe commands go to majordomo@postgresql.org
> > >
> > >
> > --
> > Dave Cramer <Dave@micro-automation.net>
> >
>
>
--
Dave Cramer <Dave@micro-automation.net>
Might Garrick come up with a test case that doesn't involve the code he's
not allowed to show? it may just be something as simple as a dummy
stored proc would show this behaviour on his machine.
On 27 Jun 2003, Dave Cramer wrote:
> Garrick,
>
> You are correct, it should run in the same time over the jdbc
> connection.
> Obviously there is a problem somewhere, but given that something like
>
> select nextval(...) or select now() both call functions and return
> quickly.
>
> I am at a loss to explain the behaviour.
>
> If I can't see it on my machine, how can I fix it?
>
>
> Dave
>
> On Fri, 2003-06-27 at 15:10, Garrick Dasbach wrote:
> > Unfortunately, I can't release the source for the function due to IP
> > concerns. However considering the function runs in about 40 seconds
> > through the psql terminal, should it matter what the function does since
> > it should run in the same amount of time through JDBC?
> >
> > Garrick
> >
> >
> > On Fri, 2003-06-27 at 14:02, Dave Cramer wrote:
> > > Garrick,
> > >
> > > Given that nextval('sequence') is a function and I do those all the
> > > time, I would probably need to see the function.
> > >
> > > Dave
> > > On Fri, 2003-06-27 at 14:58, Garrick Dasbach wrote:
> > > > It's about as simple a JDBC program as you can get. Source included
> > > > below, minus company info ofcourse.
> > > >
> > > > public static void main(String[] args) {
> > > > Connection conn = null;
> > > > Statement stmt = null;
> > > > ResultSet rs = null;
> > > > try{
> > > > Class.forName("org.postgresql.Driver");
> > > > conn = DriverManager.getConnection("jdbc:postgresql://server_ip/db_name", "user", "password");
> > > > stmt = conn.createStatement();
> > > > rs = stmt.executeQuery("select myFunction(2)");
> > > > if(rs.next()){
> > > > System.out.println("Function Execution Successfull.");
> > > > }
> > > > } catch (Exception e){
> > > > e.printStackTrace();
> > > > } finally {
> > > > try{ rs.close(); } catch (Exception e){}
> > > > try{ stmt.close(); } catch (Exception e){}
> > > > try{ conn.close(); } catch (Exception e){}
> > > > }
> > > > }
> > > >
> > > > Garick Dasbach
> > > >
> > > >
> > > > On Fri, 2003-06-27 at 13:53, Dave Cramer wrote:
> > > > > Garrick,
> > > > >
> > > > > It would help if you posted a small program to replicate the problem.
> > > > >
> > > > > Dave
> > > > > On Fri, 2003-06-27 at 14:44, Garrick Dasbach wrote:
> > > > > > I'm working on a project with Postgresql and I'm running into a strange
> > > > > > problem.
> > > > > >
> > > > > > I have a Java Program running on the Database server that periodicly
> > > > > > connects to the Database and runs a pl/pgsql function. This function
> > > > > > should run fairly fast, but could take several minutes based on the load
> > > > > > of the server and amount of information it needs to process.
> > > > > >
> > > > > > Running the function from psql takes 40 seconds under no load and
> > > > > > minimal data, but when I run the function from java using JDBC it takes
> > > > > > 20-30 minutes.
> > > > > >
> > > > > > Checking top, this is a Linux system, I see that the java program takes
> > > > > > up 99% of the CPU when it's running this function through executeQuery.
> > > > > > Is executeQuery() doing a busy wait for the data from postgres? It
> > > > > > seems a bit absurd that the executeQuery method would hijack 99% of the
> > > > > > CPU waiting for results and slowing everything else on the system down.
> > > > > >
> > > > > > The second problem I am noticing is that if I move the java program to
> > > > > > another machine, to keep java from stealing all the CPU cycles, the
> > > > > > function still takes 20-30 minutes to run through java, but only takes
> > > > > > 40 seconds to run through psql. What's the deal?
> > > > > >
> > > > > > Any help would be appreciated.
> > > > > >
> > > > > > Garrick Dasbach
> > > > > >
> > > > > > Software Developer
> > > > > > MusicRebellion.com, Inc.
> > > > > > Garrick@musicrebellion.com
> > > > > >
> > > > > >
> > > > > > ---------------------------(end of broadcast)---------------------------
> > > > > > TIP 9: the planner will ignore your desire to choose an index scan if your
> > > > > > joining column's datatypes do not match
> > > > > >
> > > > > --
> > > > > Dave Cramer <Dave@micro-automation.net>
> > > > >
> > > > >
> > > > > ---------------------------(end of broadcast)---------------------------
> > > > > TIP 1: subscribe and unsubscribe commands go to majordomo@postgresql.org
> > > >
> > > >
> > > --
> > > Dave Cramer <Dave@micro-automation.net>
> > >
> >
> >
>
Well, we found the problem. Using a Packet Sniffer we found that
Postgres was sending Thousands of 8K messages back to our JDBC test
Program. Inside these packets were the text from the 'NOTICE' commands
we were using to debug our function. We didn't realize that Postgres
sent these messages back. Thus our program was constantly recieving
information, and Postgres could only continue processing the transaction
when it's output buffer had been cleared.
Now that we know what's going on, is there any way to tap into these
NOTICE messages from the server? Maybe to use as way to track a
function's execution/progress from JDBC.
Thanks for your patience.
Garrick
On Fri, 2003-06-27 at 14:21, Dave Cramer wrote:
> Garrick,
>
> You are correct, it should run in the same time over the jdbc
> connection.
> Obviously there is a problem somewhere, but given that something like
>
> select nextval(...) or select now() both call functions and return
> quickly.
>
> I am at a loss to explain the behaviour.
>
> If I can't see it on my machine, how can I fix it?
>
>
> Dave
>
> On Fri, 2003-06-27 at 15:10, Garrick Dasbach wrote:
> > Unfortunately, I can't release the source for the function due to IP
> > concerns. However considering the function runs in about 40 seconds
> > through the psql terminal, should it matter what the function does since
> > it should run in the same amount of time through JDBC?
> >
> > Garrick
> >
> >
> > On Fri, 2003-06-27 at 14:02, Dave Cramer wrote:
> > > Garrick,
> > >
> > > Given that nextval('sequence') is a function and I do those all the
> > > time, I would probably need to see the function.
> > >
> > > Dave
> > > On Fri, 2003-06-27 at 14:58, Garrick Dasbach wrote:
> > > > It's about as simple a JDBC program as you can get. Source included
> > > > below, minus company info ofcourse.
> > > >
> > > > public static void main(String[] args) {
> > > > Connection conn = null;
> > > > Statement stmt = null;
> > > > ResultSet rs = null;
> > > > try{
> > > > Class.forName("org.postgresql.Driver");
> > > > conn = DriverManager.getConnection("jdbc:postgresql://server_ip/db_name", "user", "password");
> > > > stmt = conn.createStatement();
> > > > rs = stmt.executeQuery("select myFunction(2)");
> > > > if(rs.next()){
> > > > System.out.println("Function Execution Successfull.");
> > > > }
> > > > } catch (Exception e){
> > > > e.printStackTrace();
> > > > } finally {
> > > > try{ rs.close(); } catch (Exception e){}
> > > > try{ stmt.close(); } catch (Exception e){}
> > > > try{ conn.close(); } catch (Exception e){}
> > > > }
> > > > }
> > > >
> > > > Garick Dasbach
> > > >
> > > >
> > > > On Fri, 2003-06-27 at 13:53, Dave Cramer wrote:
> > > > > Garrick,
> > > > >
> > > > > It would help if you posted a small program to replicate the problem.
> > > > >
> > > > > Dave
> > > > > On Fri, 2003-06-27 at 14:44, Garrick Dasbach wrote:
> > > > > > I'm working on a project with Postgresql and I'm running into a strange
> > > > > > problem.
> > > > > >
> > > > > > I have a Java Program running on the Database server that periodicly
> > > > > > connects to the Database and runs a pl/pgsql function. This function
> > > > > > should run fairly fast, but could take several minutes based on the load
> > > > > > of the server and amount of information it needs to process.
> > > > > >
> > > > > > Running the function from psql takes 40 seconds under no load and
> > > > > > minimal data, but when I run the function from java using JDBC it takes
> > > > > > 20-30 minutes.
> > > > > >
> > > > > > Checking top, this is a Linux system, I see that the java program takes
> > > > > > up 99% of the CPU when it's running this function through executeQuery.
> > > > > > Is executeQuery() doing a busy wait for the data from postgres? It
> > > > > > seems a bit absurd that the executeQuery method would hijack 99% of the
> > > > > > CPU waiting for results and slowing everything else on the system down.
> > > > > >
> > > > > > The second problem I am noticing is that if I move the java program to
> > > > > > another machine, to keep java from stealing all the CPU cycles, the
> > > > > > function still takes 20-30 minutes to run through java, but only takes
> > > > > > 40 seconds to run through psql. What's the deal?
> > > > > >
> > > > > > Any help would be appreciated.
> > > > > >
> > > > > > Garrick Dasbach
> > > > > >
> > > > > > Software Developer
> > > > > > MusicRebellion.com, Inc.
> > > > > > Garrick@musicrebellion.com
> > > > > >
> > > > > >
> > > > > > ---------------------------(end of broadcast)---------------------------
> > > > > > TIP 9: the planner will ignore your desire to choose an index scan if your
> > > > > > joining column's datatypes do not match
> > > > > >
> > > > > --
> > > > > Dave Cramer <Dave@micro-automation.net>
> > > > >
> > > > >
> > > > > ---------------------------(end of broadcast)---------------------------
> > > > > TIP 1: subscribe and unsubscribe commands go to majordomo@postgresql.org
> > > >
> > > >
> > > --
> > > Dave Cramer <Dave@micro-automation.net>
> > >
> >
> >
> --
> Dave Cramer <Dave@micro-automation.net>
>
Garrick Dasbach <Garrick@musicrebellion.com> writes:
> Well, we found the problem. Using a Packet Sniffer we found that
> Postgres was sending Thousands of 8K messages back to our JDBC test
> Program. Inside these packets were the text from the 'NOTICE' commands
> we were using to debug our function. We didn't realize that Postgres
> sent these messages back.
Someone reported a comparable problem recently in libpq: they had an ON
INSERT trigger that emitted tons of NOTICEs, and they found that a COPY
into that table would hang up, because libpq's routines to process COPY
IN data transmission don't bother to look to see if there's any return
data they ought to read. Sooner or later the return path fills up and
the kernel blocks the sender (ie, the backend). This is on my to-fix
list, but I've not gotten to it yet. It sounds like JDBC has a similar
issue someplace.
regards, tom lane
tom, I don't think this is the case here, he is doing a select from his own user defined function, the funciont is emitting the notices, jdbc would be spinning on reading the notices. Dave On Sat, 2003-06-28 at 01:46, Tom Lane wrote: > Garrick Dasbach <Garrick@musicrebellion.com> writes: > > Well, we found the problem. Using a Packet Sniffer we found that > > Postgres was sending Thousands of 8K messages back to our JDBC test > > Program. Inside these packets were the text from the 'NOTICE' commands > > we were using to debug our function. We didn't realize that Postgres > > sent these messages back. > > Someone reported a comparable problem recently in libpq: they had an ON > INSERT trigger that emitted tons of NOTICEs, and they found that a COPY > into that table would hang up, because libpq's routines to process COPY > IN data transmission don't bother to look to see if there's any return > data they ought to read. Sooner or later the return path fills up and > the kernel blocks the sender (ie, the backend). This is on my to-fix > list, but I've not gotten to it yet. It sounds like JDBC has a similar > issue someplace. > > regards, tom lane > > ---------------------------(end of broadcast)--------------------------- > TIP 9: the planner will ignore your desire to choose an index scan if your > joining column's datatypes do not match > -- Dave Cramer <Dave@micro-automation.net>