Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

JDBC driver support for parallel queries? #1246

Closed
torrejonv opened this issue Jul 11, 2018 · 10 comments
Closed

JDBC driver support for parallel queries? #1246

torrejonv opened this issue Jul 11, 2018 · 10 comments

Comments

@torrejonv
Copy link

Hello,

JDBC Driver 42.2.2.
Java 10.0.1
Postgresql 10.4

During tests, we have noticed we cannot trigger parallel queries when using the JDBC. Query being executed via PSQL shows parallel query execution planned and performed (for example: "Workers Planned: 2, Workers Launched: 2".

However, running the same query via JDBC shows that the query was planned in parallel, but not executed in parallel. Typical output is: "Workers Planned: 2, Workers Launched: 0". The query is planned for parallel execution, but it is then performed in a single thread. We only see this behaviour when going via the JDBC.

The documentation comes with some notes indicating cases where parallel queries are not applicable, however we cannot see why any would apply:

"https://www.postgresql.org/docs/current/static/when-can-parallel-query-be-used.html:

"Even when parallel query plan is generated for a particular query, there are several circumstances under which it will be impossible to execute that plan in parallel at execution time. If this occurs, the leader will execute the portion of the plan below the Gather node entirely by itself, almost as if the Gather node were not present. This will happen if any of the following conditions are met:
...

  • The client sends an Execute message with a non-zero fetch count. See the discussion of the extended query protocol. Since libpq currently provides no way to send such a message, this can only occur when using a client that does not rely on libpq. If this is a frequent occurrence, it may be a good idea to set max_parallel_workers_per_gather to zero in sessions where it is likely, so as to avoid generating query plans that may be suboptimal when run serially.
    ...
  • The transaction isolation level is serializable. This situation does not normally arise, because parallel query plans are not generated when the transaction isolation level is serializable. However, it can happen if the transaction isolation level is changed to serializable after the plan is generated and before it is executed."

"

We do not modify the default isolation level, and are not using fetch size for these particular queries.

Example code (modified some bits for confidentiality), no fetch size enforced:
PreparedStatement ps = null;
ResultSet rs = null;

    try {
        String sql = "SELECT xxxxxxxxxx xxxxxx...";
        ps = connection.prepareStatement(sql);
        ps.setLong(1, xxxx);
        rs = ps.executeQuery();

....

So, we are out of ideas by now. Is the JDBC meant to be compatible with PG 10 parallel queries? If it is, is there any reason why we would experience the described behaviour?
@vlsi
Copy link
Member

vlsi commented Jul 11, 2018

@torrejonv , are you sure you use select + executeQuery?

Could you collect trace logs (see loggerLevel / loggerFile here: https://github.com/pgjdbc/pgjdbc#connection-properties) and/or provide a testcase to reproduce the issue?

@torrejonv
Copy link
Author

Hi,

Trace logs do not provide a lot (notice it is a prepared statement, so the query is not appearing):

Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE BindComplete [unnamed]
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl receiveCommandStatus
FINEST: <=BE CommandStatus(BEGIN)
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE BindComplete [C_12]
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE DataRow(len=197)
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE DataRow(len=193)
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE DataRow(len=203)
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE DataRow(len=219)
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl receiveCommandStatus
FINEST: <=BE CommandStatus(SELECT 4)
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl receiveRFQ
FINEST: <=BE ReadyForQuery(T)
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 1
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 3
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 5
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getBoolean
FINEST: getBoolean columnIndex: 6
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.BooleanTypeUtil castToBoolean
FINE: Cast to boolean: "1.0"
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getBoolean
FINEST: getBoolean columnIndex: 7
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.BooleanTypeUtil castToBoolean
FINE: Cast to boolean: "1.0"
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getBigDecimal
FINEST: getBigDecimal columnIndex: 8
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getBigDecimal
FINEST: getBigDecimal columnIndex: 9
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 10
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 11
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 12
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 1
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 3
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 5
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getBoolean
FINEST: getBoolean columnIndex: 6
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.BooleanTypeUtil castToBoolean
FINE: Cast to boolean: "1.0"
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getBoolean
FINEST: getBoolean columnIndex: 7
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.BooleanTypeUtil castToBoolean
FINE: Cast to boolean: "1.0"
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getBigDecimal
FINEST: getBigDecimal columnIndex: 8
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getBigDecimal
FINEST: getBigDecimal columnIndex: 9
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 10
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 11
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 12
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 1
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 3
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 5
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getBoolean
FINEST: getBoolean columnIndex: 6
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.BooleanTypeUtil castToBoolean
FINE: Cast to boolean: "1.0"
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getBoolean
FINEST: getBoolean columnIndex: 7
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.BooleanTypeUtil castToBoolean
FINE: Cast to boolean: "1.0"
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getBigDecimal
FINEST: getBigDecimal columnIndex: 8
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getBigDecimal
FINEST: getBigDecimal columnIndex: 9
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 10
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 11
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 12
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 1
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 3
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 5
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getBoolean
FINEST: getBoolean columnIndex: 6
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.BooleanTypeUtil castToBoolean
FINE: Cast to boolean: "1.0"
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getBoolean
FINEST: getBoolean columnIndex: 7
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.BooleanTypeUtil castToBoolean
FINE: Cast to boolean: "1.0"
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getBigDecimal
FINEST: getBigDecimal columnIndex: 8
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getBigDecimal
FINEST: getBigDecimal columnIndex: 9
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 10
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 11
Jul 11, 2018 4:44:19 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 12
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl execute
FINEST: simple execute, handler=org.postgresql.jdbc.PgConnection$TransactionCommandHandler@30e8e487, maxRows=0, fetchSize=0, flags=22
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl sendClosePortal
FINEST: FE=> ClosePortal(C_12)
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl sendBind
FINEST: FE=> Bind(stmt=S_1,portal=null)
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl sendExecute
FINEST: FE=> Execute(portal=null,limit=1)
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl sendSync
FINEST: FE=> Sync
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE CloseComplete
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE BindComplete [unnamed]
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl receiveCommandStatus
FINEST: <=BE CommandStatus(COMMIT)
Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl receiveRFQ
FINEST: <=BE ReadyForQuery(I)

For a reproducible test case - I'll come back to you with a test script.

@vlsi
Copy link
Member

vlsi commented Jul 11, 2018

I'm looking for FE=> Execute(portal={0},limit={1}) kind of message for the SQL in question.
It should clarify "fetch size" for the execute message (see

pgjdbc/pgjdbc/src/main/java/org/postgresql/core/v3/QueryExecutorImpl.java

Line 1651 in da831de

LOGGER.log(Level.FINEST, " FE=> Execute(portal={0},limit={1})", new Object[]{portal, limit});
)

As far as I understand the log is missing "execute/bind" FE messages. Could you cite them as well?

@torrejonv
Copy link
Author

Is this not it?

FINEST: simple execute, handler=org.postgresql.jdbc.PgConnection$TransactionCommandHandler@30e8e487, maxRows=0, fetchSize=0, flags=22

@vlsi
Copy link
Member

vlsi commented Jul 11, 2018

Of course it is not.
The message should literally read FE=> Execute...

Like this one:

Jul 11, 2018 4:44:19 PM org.postgresql.core.v3.QueryExecutorImpl sendExecute
FINEST: FE=> Execute(portal=null,limit=1)

However, that execute message was for a commit query.

@torrejonv
Copy link
Author

This is probably more like it, after disabling the preparedThreshold.

Jul 11, 2018 5:05:36 PM org.postgresql.core.v3.QueryExecutorImpl sendParse
FINEST: FE=> Parse(stmt=null,query="BEGIN",oids={})
Jul 11, 2018 5:05:36 PM org.postgresql.core.v3.QueryExecutorImpl sendBind
FINEST: FE=> Bind(stmt=null,portal=null)
Jul 11, 2018 5:05:36 PM org.postgresql.core.v3.QueryExecutorImpl sendExecute
FINEST: FE=> Execute(portal=null,limit=0)
Jul 11, 2018 5:05:36 PM org.postgresql.core.v3.QueryExecutorImpl sendParse
FINEST: FE=> Parse(stmt=null,query="SELECT DISTINCT
………
……..
Jul 11, 2018 5:05:36 PM org.postgresql.core.v3.QueryExecutorImpl sendBind
FINEST: FE=> Bind(stmt=null,portal=C_2,$1=<-4>,type=INT8,$2=<'{"0"}'>,type=INT8_ARRAY,$3=<'{"0"}'>,type=INT8_ARRAY,$4=<-4>,type=INT8,$5=<-4>,type=INT8,$6=,type=VARCHAR,$7=,type=INT4,$8=<1>,type=INT4,$9=<1>,type=INT4,$10=<1>,type=INT4,$11=,type=INT4,$12=,type=INT4,$13=,type=INT4,$14=,type=INT4)
Jul 11, 2018 5:05:36 PM org.postgresql.core.v3.QueryExecutorImpl sendDescribePortal
FINEST: FE=> Describe(portal=C_2)
Jul 11, 2018 5:05:36 PM org.postgresql.core.v3.QueryExecutorImpl sendExecute
FINEST: FE=> Execute(portal=C_2,limit=20)
Jul 11, 2018 5:05:36 PM org.postgresql.core.v3.QueryExecutorImpl sendSync
FINEST: FE=> Sync

Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE ParseComplete [null]
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE BindComplete [unnamed]
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveCommandStatus
FINEST: <=BE CommandStatus(BEGIN)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE ParseComplete [null]
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE BindComplete [C_2]
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveFields
FINEST: <=BE RowDescription(12)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveFields
FINEST: Field(id,INT8,8,T)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveFields
FINEST: Field(createddate,TIMESTAMPTZ,8,T)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveFields
FINEST: Field(description,VARCHAR,65535,T)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveFields
FINEST: Field(transactiontypeid,INT8,8,T)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveFields
FINEST: Field(subtypeid,INT8,8,T)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveFields
FINEST: Field(VOIDYN,INT8,8,T)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveFields
FINEST: Field(settledyn,INT2,2,T)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveFields
FINEST: Field(debit,NUMERIC,65535,T)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveFields
FINEST: Field(credit,NUMERIC,65535,T)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveFields
FINEST: Field(username,VARCHAR,65535,T)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveFields
FINEST: Field(accountid,INT8,8,T)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveFields
FINEST: Field(agentpercentage,NUMERIC,65535,T)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE DataRow(len=197)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE DataRow(len=193)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE DataRow(len=202)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE DataRow(len=218)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveCommandStatus
FINEST: <=BE CommandStatus(SELECT 4)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveRFQ
FINEST: <=BE ReadyForQuery(T)
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 1
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 2
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 3
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 5
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getBoolean
FINEST: getBoolean columnIndex: 6
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 6
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.BooleanTypeUtil castToBoolean
FINE: Cast to boolean: "1"
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getBoolean
FINEST: getBoolean columnIndex: 7
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 7
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.BooleanTypeUtil castToBoolean
FINE: Cast to boolean: "1"
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getBigDecimal
FINEST: getBigDecimal columnIndex: 8
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getBigDecimal
FINEST: getBigDecimal columnIndex: 9
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 10
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 11
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 12
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 1
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 2
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 3
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 5
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getBoolean
FINEST: getBoolean columnIndex: 6
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 6
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.BooleanTypeUtil castToBoolean
FINE: Cast to boolean: "1"
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getBoolean
FINEST: getBoolean columnIndex: 7
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 7
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.BooleanTypeUtil castToBoolean
FINE: Cast to boolean: "1"
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getBigDecimal
FINEST: getBigDecimal columnIndex: 8
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getBigDecimal
FINEST: getBigDecimal columnIndex: 9
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 10
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 11
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 12
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 1
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 2
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 3
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 5
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getBoolean
FINEST: getBoolean columnIndex: 6
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 6
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.BooleanTypeUtil castToBoolean
FINE: Cast to boolean: "1"
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getBoolean
FINEST: getBoolean columnIndex: 7
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 7
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.BooleanTypeUtil castToBoolean
FINE: Cast to boolean: "1"
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getBigDecimal
FINEST: getBigDecimal columnIndex: 8
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getBigDecimal
FINEST: getBigDecimal columnIndex: 9
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 10
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 11
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 12
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 1
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 2
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 3
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 5
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getBoolean
FINEST: getBoolean columnIndex: 6
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 6
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.BooleanTypeUtil castToBoolean
FINE: Cast to boolean: "1"
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getBoolean
FINEST: getBoolean columnIndex: 7
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 7
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.BooleanTypeUtil castToBoolean
FINE: Cast to boolean: "1"
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getBigDecimal
FINEST: getBigDecimal columnIndex: 8
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getBigDecimal
FINEST: getBigDecimal columnIndex: 9
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getString
FINEST: getString columnIndex: 10
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 11
Jul 11, 2018 5:05:38 PM org.postgresql.jdbc.PgResultSet getLong
FINEST: getLong columnIndex: 12
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl execute
FINEST: simple execute, handler=org.postgresql.jdbc.PgConnection$TransactionCommandHandler@1b9a4873, maxRows=0, fetchSize=0, flags=22
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl sendClosePortal
FINEST: FE=> ClosePortal(C_2)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl sendBind
FINEST: FE=> Bind(stmt=S_1,portal=null)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl sendExecute
FINEST: FE=> Execute(portal=null,limit=1)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl sendSync
FINEST: FE=> Sync
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE CloseComplete
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl processResults
FINEST: <=BE BindComplete [unnamed]
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveCommandStatus
FINEST: <=BE CommandStatus(COMMIT)
Jul 11, 2018 5:05:38 PM org.postgresql.core.v3.QueryExecutorImpl receiveRFQ
FINEST: <=BE ReadyForQuery(I)

@vlsi
Copy link
Member

vlsi commented Jul 11, 2018

That is you are using limit=20.

It can come from:
statement.setFetchSize(int) (defaults to 0)
statement.setMaxRows(int) (defaults to 0)
statement.setLargeMaxRows(long) (it is not implemented yet in pgjdbc)
defaultRowFetchSize connection property (defaults to 0)

Could you please double-check setMaxRows and/or setFetchSize?

@torrejonv
Copy link
Author

OK, this is definitely a pointer for us.

For what I can see, pstmt.getFetchSize() is indeed 20. Nothing is modifying the pstmt (it's just created "as conn.prepareStatement(sql)"), so this seems to be a limit in the connection itself. ((PgConnection) JdbcTools.unwrappedConnection(conn)).getDefaultFetchSize() == 0 though.

We will investigate it on this end, now that we have a pointer.

@vlsi
Copy link
Member

vlsi commented Jul 11, 2018

Could you add a breakpoint into org.postgresql.jdbc.PgStatement#setFetchSize?

@torrejonv
Copy link
Author

OK problem solved! We had a connection wrapper modifying the fetch size - that affected all prepared statements by default.

Thank you for the help troubleshooting this, Vladimir. WE are now seeing parallel queries.

@ericcj ericcj mentioned this issue Mar 8, 2024
Open
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@vlsi @torrejonv