Question about connection pool settings when using gs-loader.sh

Hi,

I have the following setup for my GridSQL setup with 2 nodes (both pointing to the same Postgres server)

I have not modified the jdbc pool parameters and assume that the values will be picked up based upon the thread pool settings above.

I have some batch processing that kicks off and invokes several gs-loader.sh processes in parallel to load data into the database. I noticed that sometimes I am running out of connections - I noticed that after my run there were upto 200 connections taken up on postgres by the GridSQL. (Assume that the batch processing kicked off about a 100 gs-loader processes in parallel).

Questions:

1. Is the number of connections taken up on Postgres not limited by the xdb.default.threads.pool.maxsize value in case of gs-loader processes?

- I would have expected the behavior to be that a maximum of 15 x 2 (nodes) = 30 connections would be taken up and perhaps the batch loading would get slowed down. However, it appears that each gs-loader.sh client seems to take up its own connection, which is not cleanly closed up after the gs-loader exits.

2. The connections on Postgres don't seem to time out (as I would expect after 10 minutes based upon the documented pool timeout default)

I can understand the need to raise the total number of connections on Postgres (I've set it to 500 now) - but it still does not explain the high number of connections or why they don't time out.

Can you please explain?

Thanks,

Ranga

Ranga,

Loader connections are pooled separately, and no config parameters provided at this time to limit these pools.
Pooled connections are eventually released if they are idle for more than xdb.jdbc.pool.idle ms, or xdb.default.threads.pool.idle ms, if xdb.jdbc.pool.idle is not set.
In general, it is not a good idea to start hundreds concurrent loaders. They may slow down each other.

Thanks
Andrei

Here are the currently live processes which existed before our application started again:

postgres 16372 0.9 0.3 2313540 116228 ? Ss 06:36 6:19 postgres: autovacuum worker process ted180daysN2
postgres 25028 0.0 0.0 2287872 3844 ? Ss 16:40 0:00 postgres: gridsql ted180daysN1 10.201.80.21(62709) idle
postgres 25029 0.0 0.0 2287872 3852 ? Ss 16:40 0:00 postgres: gridsql ted180daysN1 10.201.80.21(62710) idle
postgres 25030 0.0 0.0 2288364 24460 ? Ss 16:40 0:00 postgres: gridsql ted180daysN1 10.201.80.21(62711) idle
postgres 25031 0.0 0.0 2288164 24760 ? Ss 16:40 0:00 postgres: gridsql ted180daysN2 10.201.80.21(62712) idle
postgres 25032 0.0 0.0 2288072 22888 ? Ss 16:40 0:00 postgres: gridsql ted180daysN1 10.201.80.21(62713) idle
postgres 25033 0.0 0.0 2288120 23712 ? Ss 16:40 0:00 postgres: gridsql ted180daysN1 10.201.80.21(62714) idle
postgres 25034 0.0 0.0 2288092 23864 ? Ss 16:40 0:00 postgres: gridsql ted180daysN1 10.201.80.21(62715) idle
postgres 25035 0.0 0.0 2288036 24792 ? Ss 16:40 0:00 postgres: gridsql ted180daysN1 10.201.80.21(62716) idle
postgres 25036 0.0 0.0 2288068 23200 ? Ss 16:40 0:00 postgres: gridsql ted180daysN2 10.201.80.21(62717) idle
postgres 25037 0.0 0.0 2288112 24184 ? Ss 16:40 0:00 postgres: gridsql ted180daysN2 10.201.80.21(6271

idle
postgres 25038 0.0 0.0 2288092 24284 ? Ss 16:40 0:00 postgres: gridsql ted180daysN2 10.201.80.21(62719) idle
postgres 25039 0.0 0.0 2288160 25212 ? Ss 16:40 0:00 postgres: gridsql ted180daysN2 10.201.80.21(62720) idle
postgres 25216 2.5 0.3 2313020 106532 ? Ss 16:53 0:44 postgres: autovacuum worker process ted180daysN2

How can I obtain more information on what the idle gridsql processes were doing ?

Thanks

We see the following repeatedly in console.log:

2010-08-27 22:03:42,778 - ERROR Catching throwable:
java.io.IOException: Connection is broken
at com.edb.gridsql.protocol.PgProtocolSession.readRequest(PgProtocolSession.java:122)
at com.edb.gridsql.protocol.PgProtocolSession.run(PgProtocolSession.java:742)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:90

at java.lang.Thread.run(Thread.java:619)
Is this related to hanging connections ?

On a machine where gs loader failed, I saw this error:
Connection refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.

However, there were only 281 connections open on DB server:
-bash-3.2$ ps aux | grep ted180days | grep -v grep | wc
281 4215 34282

What could be the cause for 'Connection refused' error ?

In ObjectPool.java:
protected synchronized void packBuffer() {
while (buffer.size() > 0 && buffer.size() + out.size() > minSize) {
minSize by default is 1.
This means there would always be at least 1 PoolEntry in the pool which can explain why connection to Postgres isn't closed.

How can I obtain more information on what the idle gridsql processes were doing ?

These are the pooled connections to data nodes. They are just waiting while GridSQL start using them.

We see the following repeatedly in console.log:

2010-08-27 22:03:42,778 - ERROR Catching throwable:
java.io.IOException: Connection is broken
at com.edb.gridsql.protocol.PgProtocolSession.readRequest(PgProtocolSession.java:122)

This message means a client application unexpectedly closed connection to GridSQL.
It is not a problem, GridSQL handles this gracefully.

On a machine where gs loader failed, I saw this error:
Connection refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections.

You specified incorrect host or port, or GridSQL was not running

minSize by default is 1.
This means there would always be at least 1 PoolEntry in the pool which can explain why connection to Postgres isn't closed.

Yes. Pooling makes sense only if pool is not empty.

For 'You specified incorrect host or port, or GridSQL was not running'
Configuration on GridSQL client didn't change. Meaning host and port should be correct. GridSQL was running.

OK, third possible reason is network problem causing GridSQL server was inaccessible from the client host

Thanks
Andrei

-bash-3.2$ tail server.log
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:90

at java.lang.Thread.run(Thread.java:619)
java.lang.NoClassDefFoundError: com/edb/gridsql/parser/SqlDeleteTable
at com.edb.gridsql.parser.Parser.parse(Parser.java:595)
at com.edb.gridsql.parser.Parser.parseStatement(Parser.java:85)
at com.edb.gridsql.protocol.RequestAnalyzer.getExecutableRequest(RequestAnalyzer.java:149)
at com.edb.gridsql.protocol.PgProtocolSession.run(PgProtocolSession.java:613)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:90

at java.lang.Thread.run(Thread.java:619)

How can I configure server.log to show date/time of log entry ?

Also:
-bash-3.2$ ps aux | grep 32325
32490 28033 0.0 0.0 61136 760 pts/1 S+ 15:35 0:00 grep 32325
32490 32325 2.3 2.1 1083732 704384 ? Sl Aug27 91:55 java -classpath /usr/local/gridsql_2node/bin/xdbengine.jar:/usr/local/gridsql_2node/bin/xdbprotocol.jar:/usr/local/gridsql_2node/bin/xdbserver.jar:/usr/local/gridsql_2node/lib/edb-jdbc14.jar:/usr/local/gridsql_2node/lib/log4j.jar:/usr/local/gridsql_2node/lib/edb-jdbc14.jar: -Xms512M -Xmx512M -Xss256K -Dconfig.file.path=/usr/local/gridsql_2node/config/gridsql.config com.edb.gridsql.util.XdbServer
-bash-3.2$ jar tvf /usr/local/gridsql_2node/bin/xdbengine.jar | grep SqlDeleteTable
14555 Sun Aug 29 08:24:22 GMT+00:00 2010 com/edb/gridsql/parser/SqlDeleteTable.class

I wonder what was the cause for NoClassDefFoundError

I should have mentioned that I modified SyncCreateIndex.java slightly because of the following:

I saw this in console.log:
2010-08-28 00:34:14,687 - ERROR Throwing throwable:
com.edb.gridsql.exception.XDBServerException
at com.edb.gridsql.engine.Engine.doMetadataUpdate(Engine.java:363)
at com.edb.gridsql.engine.Engine.executeDDLOnMultipleNodes(Engine.java:330)
at com.edb.gridsql.engine.Engine.executeDDLOnMultipleNodes(Engine.java:297)
at com.edb.gridsql.parser.SqlCreateIndex.execute(SqlCreateIndex.java:417)
at com.edb.gridsql.engine.ExecutableRequest.execute(ExecutableRequest.java:244)
at com.edb.gridsql.engine.XDBSessionContext.executeRequest(XDBSessionContext.java:1037)
at com.edb.gridsql.engine.ServerStatement.execute(ServerStatement.java:201)
at com.edb.gridsql.engine.ServerStatement.describe(ServerStatement.java:145)
at com.edb.gridsql.engine.XDBSessionContext.describeStatement(XDBSessionContext.java:914)
at com.edb.gridsql.protocol.PgProtocolSession.run(PgProtocolSession.java:659)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:90

at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.NullPointerException
at com.edb.gridsql.metadata.SyncCreateIndex.execute(SyncCreateIndex.java:81)
at com.edb.gridsql.engine.Engine.doMetadataUpdate(Engine.java:350)
... 12 more

This is the line causing NPE:
indexKeys.add(new SqlCreateIndexKey(colMap.get(colName),
I went over the code and couldn't immediately identify whether indexKeys or colMap was null.

So I broke up line 81 into the following:
Integer colId = colMap.get(colName);
SqlCreateIndexKey sciKey = new SqlCreateIndexKey(colId,
colName, keyDef.isAscending() ? "ASC" : "DESC",
keyDef.getColOperator());
indexKeys.add(sciKey);

How can I configure server.log to show date/time of log entry ?

Please see http://logging.apache.org/log4j/ for details how to configure logging

I wonder what was the cause for NoClassDefFoundError

Is the error reproducible?
Please let us know your Java version and how you have built and installed GridSQL

2010-08-28 00:34:14,687 - ERROR Throwing throwable:
com.edb.gridsql.exception.XDBServerException
at com.edb.gridsql.engine.Engine.doMetadataUpdate(Engine.java:363)
at com.edb.gridsql.engine.Engine.executeDDLOnMultipleNodes(Engine.java:330)
at com.edb.gridsql.engine.Engine.executeDDLOnMultipleNodes(Engine.java:297)
at com.edb.gridsql.parser.SqlCreateIndex.execute(SqlCreateIndex.java:417)
at com.edb.gridsql.engine.ExecutableRequest.execute(ExecutableRequest.java:244)
at com.edb.gridsql.engine.XDBSessionContext.executeRequest(XDBSessionContext.java:1037)
at com.edb.gridsql.engine.ServerStatement.execute(ServerStatement.java:201)
at com.edb.gridsql.engine.ServerStatement.describe(ServerStatement.java:145)
at com.edb.gridsql.engine.XDBSessionContext.describeStatement(XDBSessionContext.java:914)
at com.edb.gridsql.protocol.PgProtocolSession.run(PgProtocolSession.java:659)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:90
at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.NullPointerException
at com.edb.gridsql.metadata.SyncCreateIndex.execute(SyncCreateIndex.java:81)
at com.edb.gridsql.engine.Engine.doMetadataUpdate(Engine.java:350)
... 12 more

This is probably a bug. Is it reproducible? Can you let us know steps to reproduce?

This message was edited 2 times. Last update was at 30 Aug 2010 12:33:14

On the build machine:

Under /usr/local/software/gridsql-cvs-may26/apps/gridsql, I typed make

...
sed: read error on ../../apps/gridsql/src/config/agent/CVS: Is a directory
Can not install: ../../apps/gridsql/src/config/agent/CVS
install: cannot stat `../../apps/gridsql/obj/gridsql_agent.config': No such file or directory
Can not install: ../../apps/gridsql/src/config/agent/gridsql_agent.config

[root@sjc9-flash-db01 gridsql]# ls -l lib/xdbengine.jar
-rw-r--r-- 1 root root 1759697 Aug 29 15:24 lib/xdbengine.jar

I copied lib/xdbengine.jar to /usr/local/gridsql_2node/bin/xdbengine.jar on the GridSQL server

Here is the Java version on GridSQL server:
-bash-3.2$ java -version
java version "1.6.0_20"
Java(TM) SE Runtime Environment (build 1.6.0_20-b02)
Java HotSpot(TM) 64-Bit Server VM (build 16.3-b01, mixed mode)

I didn't restart GridSQL because I got the following error when I tried to stop the DB we used:

-bash-3.2$ gs-dbstop.sh -u admx -p sey -d ted180days
ERROR: com/edb/gridsql/parser/core/syntaxtree/StopDatabase
Parameters: <connect> -d <database>
where <connect> is -j jdbc:edb://<host>:<port>/<database>?user=<username>&password=<password>
or [-h <host>] [-s <port>] -d <database> -u <user> [-p <password>]
-h <host> : Host name or IP address where XDBServer is running. Default is localhost
-s <port> : XDBServer's port. Default is 6453
-d <database> : Name of databases to stop.
-u <user>, -p <password> : Login to the database.

This message was edited 1 time. Last update was at 30 Aug 2010 12:35:27

please use "make GridSQL" to build
copy all lib/xdb*.jar to install
shutdown server before installing and start again after

I also introduced config parameter, xdb.jdbc.pool.minsize, in LoaderConnectionPool.getConnection():
pool = new JDBCPool(aJdbcDriver,
ParseCmdLine.substitute(aJdbcString, m),
m.get("dbusername"),
m.get("dbpassword"),
Property.getInt("xdb.jdbc.pool.minsize", 0),
Integer.MAX_VALUE);

-bash-3.2$ gs-dbstop.sh -j jdbc:edb://sjc1-spr-db-diq00.sjc1.carrieriq.com:6453/ted180days?user=admin2node&password=secret -d ted180days[1] 29884
-bash: -d: command not found
-bash-3.2$ Unknown argument: -j
Parameters: <connect> -d <database>
where <connect> is -j jdbc:edb://<host>:<port>/<database>?user=<username>&password=<password>
or [-h <host>] [-s <port>] -d <database> -u <user> [-p <password>]
-h <host> : Host name or IP address where XDBServer is running. Default is localhost
-s <port> : XDBServer's port. Default is 6453
-d <database> : Name of databases to stop.
-u <user>, -p <password> : Login to the database.

[1]+ Exit 1 gs-dbstop.sh -j jdbc:edb://sjc1-spr-db-diq00.sjc1.carrieriq.com:6453/ted180days?user=admin2node

I didn't modify bin/xdbutil.jar
Please advise how to use gs-dbstop.sh

-bash-3.2$ gs-dbstop.sh -h sjc1-spr-db-diq00.sjc1.carrieriq.com -s 6453 -d ted180days -u admi -p sec
ERROR: com/edb/gridsql/parser/core/syntaxtree/StopDatabase

You have already broken things. Just kill GridSQL server process and agents if you are using them.

Can you briefly describe the changes you made for http://forums.enterprisedb.com/posts/list/2259.page ?
What is the CVS setup for GridSQL source code ?

Thanks

You can find CVS connection details at the SourceForge:
http://sourceforge.net/projects/gridsql/develop

I made one method synchronized, but this did not seem to fix the problem.
Please see src/com/edb/gridsql/engine/Engine.java;v1.4
Unfortunately I could not reproduce it.

Thanks
Andrei

If I obtain dump of XdbServer process, would I be able to upload the dump somewhere so that you can take a look ?

Sure, if you obtain a dump or anything else that might be helpful please share it with us.
Please pm me for uploading details or use any file sharing service of your preference.

I don't have ftp server for public.
If you have one, please send login information to ted_yu@yahoo.com

I have sent an email to you.
I would advise you to remove your email address from the public forum: spammer's spiders are not sleeping