Обсуждение: BUG #1347: Bulk Import stopps after a while ( 8.0.0. RC1)
The following bug has been logged online:
Bug reference: 1347
Logged by: Bahadur Singh
Email address: bahadursingh@yahoo.com
PostgreSQL version: 8.0 Beta
Operating system: Windows XP
Description: Bulk Import stopps after a while ( 8.0.0. RC1)
Details:
Hello,
I have found a trivial problem during the bulk import of data.
I have a following situation.
- I have 2 big table on SQL Server 2000 with 163000 rows each.
- I have written a java program to transfer data from SQL Server 2000 to
PosgresSQL 8.0.0 RC1 release. I am updating the data in batches.
If my batch size is 1000/2000 records at a time.. This works fine.. And if I
change this size to say 20,000, it does only finishes one loop.. and then
stays idle. The CPU usage down to 10 % which was before 100 % while applying
the first batch of 20, 000 records.
The execution of program is halting just at
int n [] = stmt.batchUpdate();
I waited one hours at the most to wait above instruction to finish and then
stopped manually.. I am not sure that is it JDBC error or PostgreSQL error.
I am using JDBC release of PosgresSQL 8.0.0 RC1 release.
Thanks
Bahadur
Include :
Log 1 : when does not work..
Log 2 : when works ..
------------------ Log 1 ----------------
WHEN BATCH SIZE = 2000
---------------
getMsSqlConnection() :: status = ACTIVE
getPgSqlConnection() :: status = ACTIVE
Fri Dec 10 16:47:23 CET 2004 Migration: CREATE TABLE EodIDC_S (
"transstep" int,
"transactionid" int,
"departmentnumber" char (4),
"plunumber" char (16),
"identnumber" char (16),
"quantity" int,
"quantitydecimals" int,
"packingunit" int,
"mmcode" int,
"amountsign" char (1),
"amountabsolute" int,
"code1" char (1),
"code2" char (1),
"code3" char (1),
"idcdate" char (14),
"originalitemprice" int,
PRIMARY KEY ( TransactionId,TransStep ) )
Fri Dec 10 16:47:23 CET 2004 Migration: CREATE TABLE EodIDC_S FINISHED
Fri Dec 10 16:47:23 CET 2004 Migration: CREATE TABLE EodIDC_W (
"transactionid" int,
"transstep" int,
"iteminfo" char (4),
"itemnumber" char (16),
"flag1" char (2),
"flag2" char (2),
"amount" int,
"flag3" char (2),
"code1" char (1),
"flag4" char (2),
"code2" char (1),
"code3" char (1),
"idcdate" char (14),
"plunumber" char (16),
"quantity" int,
PRIMARY KEY ( TransactionId,TransStep ) )
Fri Dec 10 16:47:23 CET 2004 Migration: CREATE TABLE EodIDC_W FINISHED
Fri Dec 10 16:47:23 CET 2004 Migration: DDL finished in 109 ms
Fri Dec 10 16:47:23 CET 2004 Migration: Exporting Table to PostgreSQL =
EodIDC_S
Fri Dec 10 16:47:23 CET 2004 Migration: Reading data from MS SQL Server
table ... EodIDC_S
Fri Dec 10 16:47:24 CET 2004 Migration: Batch sent upto = 20000
Fri Dec 10 16:47:24 CET 2004 Migration: EodIDC_S Total SQLs sent to DB=20000
Fri Dec 10 16:47:31 CET 2004 Migration: EodIDC_S Records updated in DB=20000
Fri Dec 10 16:47:32 CET 2004 Migration: Batch sent upto = 40000
Fri Dec 10 16:47:32 CET 2004 Migration: EodIDC_S Total SQLs sent to DB=20000
****** NO RESPONSE AFTER ******
Process stopped and restarted with batch size 2000 rows
------------------ Log 2 ----------------
WHEN BATCH SIZE = 2000
----------------------
Fri Dec 10 16:51:02 CET 2004 Migration: CREATE TABLE EodIDC_S (
"transstep" int,
"transactionid" int,
"departmentnumber" char (4),
"plunumber" char (16),
"identnumber" char (16),
"quantity" int,
"quantitydecimals" int,
"packingunit" int,
"mmcode" int,
"amountsign" char (1),
"amountabsolute" int,
"code1" char (1),
"code2" char (1),
"code3" char (1),
"idcdate" char (14),
"originalitemprice" int,
PRIMARY KEY ( TransactionId,TransStep ) )
Fri Dec 10 16:51:02 CET 2004 Migration: CREATE TABLE EodIDC_S FINISHED
Fri Dec 10 16:51:02 CET 2004 Migration: CREATE TABLE EodIDC_W (
"transactionid" int,
"transstep" int,
"iteminfo" char (4),
"itemnumber" char (16),
"flag1" char (2),
"flag2" char (2),
"amount" int,
"flag3" char (2),
"code1" char (1),
"flag4" char (2),
"code2" char (1),
"code3" char (1),
"idcdate" char (14),
"plunumber" char (16),
"quantity" int,
PRIMARY KEY ( TransactionId,TransStep ) )
Fri Dec 10 16:51:02 CET 2004 Migration: CREATE TABLE EodIDC_W FINISHED
Fri Dec 10 16:51:02 CET 2004 Migration: DDL finished in 94 ms
Fri Dec 10 16:51:02 CET 2004 Migration: Exporting Table to PostgreSQL =
EodIDC_S
Fri Dec 10 16:51:02 CET 2004 Migration: Reading data from MS SQL Server
table ... EodIDC_S
Fri Dec 10 16:51:03 CET 2004 Migration: Batch sent upto = 2000
Fri Dec 10 16:51:03 CET 2004 Migration: EodIDC_S Total SQLs sent to DB=2000
Fri Dec 10 16:51:03 CET 2004 Migration: EodIDC_S Records updated in DB=2000
Fri Dec 10 16:51:03 CET 2004 Migration: Batch sent upto = 4000
Fri Dec 10 16:51:03 CET 2004 Migration: EodIDC_S Total SQLs sent to DB=2000
Fri Dec 10 16:51:04 CET 2004 Migration: EodIDC_S Records updated in DB=2000
Fri Dec 10 16:51:04 CET 2004 Migration: Batch sent upto = 6000
Fri Dec 10 16:51:04 CET 2004 Migration: EodIDC_S Total SQLs sent to DB=2000
Fri Dec 10 16:51:05 CET 2004 Migration: EodIDC_S Records updated in DB=2000
Fri Dec 10 16:51:05 CET 2004 Migration: Batch sent upto = 8000
..
..
..
..
Fri Dec 10 16:52:07 CET 2004 Migration: EodIDC_S Records updated in DB=2000
Fri Dec 10 16:52:07 CET 2004 Migration: Batch sent upto = 162000
Fri Dec 10 16:52:07 CET 2004 Migration: EodIDC_S Total SQLs sent to DB=2000
Fri Dec 10 16:52:08 CET 2004 Migration: EodIDC_S Records updated in DB=2000
Fri Dec 10 16:52:08 CET 2004 Migration: Complete Batch sent = 163492
Fri Dec 10 16:52:08 CET 2004 Migration: Total SQL=1492
Fri Dec 10 16:52:08 CET 2004 Migration: Records updated 1492
Fri Dec 10 16:52:08 CET 2004 Migration: Exporting Table to PostgreSQL =
EodIDC_S DONE
**** THE DATA WAS IMPORTED SUCCESSFULLY *****
************ JAVA METHOD ***************
private void insertBulkData (ArrayList insertSqlList, String tableName,
boolean save ) throws Exception {
// update
try {
Connection con = getPgSqlConnection();
con.setAutoCommit(false);
Statement stmt = con.createStatement();
for (Iterator sqls = insertSqlList.iterator(); sqls.hasNext(); ) {
String sql = (String)sqls.next();
stmt.addBatch(sql);
}
log( tableName + " Total SQLs sent to DB=" + insertSqlList.size());
int n [] = stmt.executeBatch();
stmt.close();
log( tableName + " Records updated in DB=" + n.length );
if (save) {
con.commit();
}
} catch (SQLException e) {
e.printStackTrace();
throw e;
} catch (Throwable te) {
te.printStackTrace();
}
}
On Mon, 13 Dec 2004, PostgreSQL Bugs List wrote:
>
> The following bug has been logged online:
>
> Bug reference: 1347
> PostgreSQL version: 8.0 Beta
> Operating system: Windows XP
> Description: Bulk Import stopps after a while ( 8.0.0. RC1)
>
> - I have written a java program to transfer data from SQL Server 2000 to
> PosgresSQL 8.0.0 RC1 release. I am updating the data in batches.
> If my batch size is 1000/2000 records at a time.. This works fine.. And if I
> change this size to say 20,000, it does only finishes one loop.. and then
> stays idle. The CPU usage down to 10 % which was before 100 % while applying
> the first batch of 20, 000 records.
>
>
> The execution of program is halting just at
> int n [] = stmt.batchUpdate();
>
This may be a problem with the JDBC driver deadlocking as described in the
below code comment. When originally written I asked Oliver about the
estimate of MAX_BUFFERED_QUERIES and he felt confident in that number. It
would be good to know if lowering this number fixes your problem.
Kris Jurka
// Deadlock avoidance:
//
// It's possible for the send and receive streams to get
// "deadlocked" against each other since we do not have a separate
// thread. The scenario is this: we have two streams:
//
// driver -> TCP buffering -> server
// server -> TCP buffering -> driver
//
// The server behaviour is roughly:
// while true:
// read message
// execute message
// write results
//
// If the server -> driver stream has a full buffer, the write will
// block. If the driver is still writing when this happens, and the
// driver -> server stream also fills up, we deadlock: the driver is
// blocked on write() waiting for the server to read some more data,
// and the server is blocked on write() waiting for the driver to read
// some more data.
//
// To avoid this, we guess at how many queries we can send before the
// server -> driver stream's buffer is full (MAX_BUFFERED_QUERIES).
// This is the point where the server blocks on write and stops
// reading data. If we reach this point, we force a Sync message and
// read pending data from the server until ReadyForQuery,
// then go back to writing more queries unless we saw an error.
//
// This is not 100% reliable -- it's only done in the batch-query case
// and only at a reasonably high level (per query, not per message),
// and it's only an estimate -- so it might break. To do it correctly
// in all cases would seem to require a separate send or receive
// thread as we can only do the Sync-and-read-results operation at
// particular points, and also as we don't really know how much data
// the server is sending.
// Assume 64k server->client buffering and 250 bytes response per
// query (conservative).
private static final int MAX_BUFFERED_QUERIES = (64000 / 250);
Kris Jurka <books@ejurka.com> writes:
> // To avoid this, we guess at how many queries we can send before the
> // server -> driver stream's buffer is full (MAX_BUFFERED_QUERIES).
It seems essentially impossible for the driver to do this reliably,
since it has no clue how much data any one query will return.
How about instead thinking in terms of not filling the driver->server
channel? You have a good handle on how much data you have sent (or at
least you could keep track of that), and if you bound it to 64K or so
then you should be safe. Perhaps the limit ought to be easily
configurable just in case, but at least you'd be measuring something
measurable.
regards, tom lane
Tom Lane wrote: > Kris Jurka <books@ejurka.com> writes: > >> // To avoid this, we guess at how many queries we can send before the >> // server -> driver stream's buffer is full (MAX_BUFFERED_QUERIES). > > > It seems essentially impossible for the driver to do this reliably, > since it has no clue how much data any one query will return. Right, but I'm not convinced that this is the problem here as batch execution in JDBC is only allowed to do non-result-set-returning queries. The only case I can think of where this would break is if something is causing lots of logging output to the client (triggers etc.). > How about instead thinking in terms of not filling the driver->server > channel? You have a good handle on how much data you have sent (or at > least you could keep track of that), and if you bound it to 64K or so > then you should be safe. Perhaps the limit ought to be easily > configurable just in case, but at least you'd be measuring something > measurable. That's possibly a better idea but it does mean that we wouldn't be able to batch inserts that contain lots of data. That's the use case I needed to support when I wrote this in the first place.. Also, it's never going to be 100% without a separate thread, as the server can spontaneously generate output (e.g. because of NOTIFY) regardless of how careful we are with our queries. There's actually another problem with this code: the subdivision into smaller batches is not transparent if autocommit is on. We send a Sync at the end of the batch which will cause an implicit commit. We should be sending a Flush, but it's harder for the driver to handle this as a Flush does not provoke a response message from the server, so we would have to track the protocol state more closely. Given that JDBC is silent about the autocommit semantics of batch execution anyway, I'm not too worried about fixing this urgently. I'd like to see that this is really the problem before tweaking this code. Given that the OP said that batch sizes of 1000-2000 worked OK, I'm not sure that this code is the problem since the maximum number of queries we'll send per batch is around 250 by default. -O
Kris Jurka wrote:
>
> On Mon, 13 Dec 2004, PostgreSQL Bugs List wrote:
>
>
>>The following bug has been logged online:
>>
>>Bug reference: 1347
>>PostgreSQL version: 8.0 Beta
>>Operating system: Windows XP
>>Description: Bulk Import stopps after a while ( 8.0.0. RC1)
>>
>> - I have written a java program to transfer data from SQL Server 2000 to
>>PosgresSQL 8.0.0 RC1 release. I am updating the data in batches.
>>If my batch size is 1000/2000 records at a time.. This works fine.. And if I
>>change this size to say 20,000, it does only finishes one loop.. and then
>>stays idle. The CPU usage down to 10 % which was before 100 % while applying
>>the first batch of 20, 000 records.
>>
>>
>>The execution of program is halting just at
>>int n [] = stmt.batchUpdate();
>>
>
>
> This may be a problem with the JDBC driver deadlocking as described in the
> below code comment. When originally written I asked Oliver about the
> estimate of MAX_BUFFERED_QUERIES and he felt confident in that number. It
> would be good to know if lowering this number fixes your problem. [...]
I'm not convinced that this is the problem as MAX_BUFFERED_QUERIES is
around 250 by default, and yet batches of 1000/2000 execute OK.
Note that I haven't seen much benefit to batch sizes above perhaps 50 on
a LAN anyway. Batch sizes of 20,000 are almost certainly excessive (but
the driver shouldn't fail!)
Are you executing the batch with autocommit on or off?
Anyway, there are two bits of debug output that would be useful to see:
1. A thread dump of the importing JVM when it gets stuck. On unix-like
systems you'd do this by sending the JVM a SIGQUIT. I don't know how
you'd do the same under Windows.
2. Driver debug output:
a. add "?logLevel=2" to the driver URL
b. set a log writer on DriverManager at the start of the run:
// Point this somewhere else, e.g. to a file,
// if it's more convenient.
java.sql.DriverManager.setLogWriter(
new java.io.PrintWriter(System.err)))
This should trace all the protocol messages being sent or received to
System.err. If the driver is wedging at the protocol level, it should
show up in that output. Send me this output off-list and compressed --
it'll be pretty big for 20,000+ queries!
-O