search

ClickHouse / clickhouse-java

ClickHouse Java Clients & JDBC Driver
https://clickhouse.com
Apache License 2.0
1.45k stars 534 forks source link

Query with id is already running. (QUERY_WITH_SAME_ID_IS_ALREADY_RUNNING) #1529

Open somemistake opened 9 months ago

somemistake commented 9 months ago

I queried with namedParameterJdbcTemplate in for loop. But sometimes driver prompts " Query with id = xxxxxx is already running.

This is my code

IntStream
                    .range(0, config.getPartitionCount())
                    .mapToObj(PartitionUtils::getPartition)
                    .forEach( partition ->
                            namedParameterJdbcTemplate.execute(
                               "OPTIMIZE TABLE transaction_operation PARTITION :partition FINAL DEDUPLICATE",
                                new MapSqlParameterSource("partition", Integer.parseInt(partition)),
                                PreparedStatement::execute
                            );
                    );

Code: 216. DB::Exception: Query with id = 2b82eae6-e0f3-47dc-a857-2bb02dff7bbd is already running. (QUERY_WITH_SAME_ID_IS_ALREADY_RUNNING) (version 22.2.2.1)

driver version: com.clickhouse:clickhouse-jdbc:0.4.6

chernser commented 5 months ago

I was able to reproduce the problem with multiple threads. Fixing this would need some refactoring.

chernser commented 4 months ago

If statements are called from different threads then it is clear what happening: 

pool-1-thread-1: Executing select 1 queryID Optional[b48cef26-a612-4196-b779-df87e6a5a174] queryId: b48cef26-a612-4196-b779-df87e6a5a174
pool-1-thread-2: Executing select 1 queryID Optional[91bfa2ec-3767-4207-8f69-f4b5836512b5] queryId: 91bfa2ec-3767-4207-8f69-f4b5836512b5
pool-1-thread-3: Executing select 1 queryID Optional[dc94f299-92a6-487e-9dbb-d0943507352d] queryId: dc94f299-92a6-487e-9dbb-d0943507352d
pool-1-thread-2 sealing: 86939426533300 91bfa2ec-3767-4207-8f69-f4b5836512b5
pool-1-thread-1 sealing: 86939426523800 91bfa2ec-3767-4207-8f69-f4b5836512b5
pool-1-thread-3 sealing: 86939426576200 91bfa2ec-3767-4207-8f69-f4b5836512b5
pool-1-thread-1 error: Code: 216. DB::Exception: Query with id = 91bfa2ec-3767-4207-8f69-f4b5836512b5 is already running. (QUERY_WITH_SAME_ID_IS_ALREADY_RUNNING) (version 24.4.1.2088 (official build))

The next code after pool-1-thread-3 sealing: 86939426576200 91bfa2ec-3767-4207-8f69-f4b5836512b5 is 

    req.queryId = queryId;

It is clearly seen that all three thread will use same queryId and if the one query runs longer - then error happens.

vietpm commented 3 months ago

Hi. I use DBeaver and update clickhouse-java to lastest version 0.6.3 but still got the same issue. SQL Error [216] [07000]: Code: 216. DB::Exception: Query with id = fc6ff4fd-f387-43f6-a1c4-84650b21b7bb is already running. (QUERY_WITH_SAME_ID_IS_ALREADY_RUNNING) (version 24.6.1.4423 (official build))

mih-kopylov commented 3 months ago

Same thing. The issue is still there.

@chernser could you please reopen the ticket?

java.sql.SQLException: Code: 216. DB::Exception: Query with id = cc17abdd-1029-45f9-bb45-4cb4d5d15865 is already running. (QUERY_WITH_SAME_ID_IS_ALREADY_RUNNING) (version 23.12.1.1368 (official build))

    at com.clickhouse.jdbc.SqlExceptionUtils.handle(SqlExceptionUtils.java:85)
    at com.clickhouse.jdbc.SqlExceptionUtils.create(SqlExceptionUtils.java:31)
    at com.clickhouse.jdbc.SqlExceptionUtils.handle(SqlExceptionUtils.java:90)
    at com.clickhouse.jdbc.internal.ClickHouseStatementImpl.sendRequest(ClickHouseStatementImpl.java:371)
    at com.clickhouse.jdbc.internal.ClickHouseStatementImpl.executeInsert(ClickHouseStatementImpl.java:382)
    at com.clickhouse.jdbc.internal.StreamBasedPreparedStatement.executeAny(StreamBasedPreparedStatement.java:97)
    at com.clickhouse.jdbc.internal.StreamBasedPreparedStatement.executeLargeUpdate(StreamBasedPreparedStatement.java:161)
    at com.clickhouse.jdbc.internal.AbstractPreparedStatement.executeUpdate(AbstractPreparedStatement.java:135)

Caused by: java.io.IOException: Code: 216. DB::Exception: Query with id = cc17abdd-1029-45f9-bb45-4cb4d5d15865 is already running. (QUERY_WITH_SAME_ID_IS_ALREADY_RUNNING) (version 23.12.1.1368 (official build))

    at com.clickhouse.client.http.ApacheHttpConnectionImpl.checkResponse(ApacheHttpConnectionImpl.java:221)
    at com.clickhouse.client.http.ApacheHttpConnectionImpl.post(ApacheHttpConnectionImpl.java:284)
    at com.clickhouse.client.http.ClickHouseHttpClient.send(ClickHouseHttpClient.java:195)
    at com.clickhouse.client.AbstractClient.execute(AbstractClient.java:280)
    at com.clickhouse.client.ClickHouseClientBuilder$Agent.sendOnce(ClickHouseClientBuilder.java:282)
    at com.clickhouse.client.ClickHouseClientBuilder$Agent.retry(ClickHouseClientBuilder.java:232)
    at com.clickhouse.client.ClickHouseClientBuilder$Agent.handle(ClickHouseClientBuilder.java:269)
    at com.clickhouse.client.ClickHouseClientBuilder$Agent.send(ClickHouseClientBuilder.java:296)
    at com.clickhouse.client.ClickHouseClientBuilder$Agent.execute(ClickHouseClientBuilder.java:349)
    at com.clickhouse.client.ClickHouseClient.executeAndWait(ClickHouseClient.java:878)
    at com.clickhouse.client.ClickHouseRequest.executeAndWait(ClickHouseRequest.java:2154)
    at com.clickhouse.jdbc.internal.ClickHouseStatementImpl.sendRequest(ClickHouseStatementImpl.java:362)
chernser commented 3 months ago

@mih-kopylov @vietpm Thanks for reporting!

  1. Do you both use DBeaver?
  2. @vietpm do you have full stack trace?
  3. Does it happen with any query, randomly, only with long running?

Thanks!

mih-kopylov commented 3 months ago

I'm using it in a regular java service while inserting data into ClickHouse tables.

The error happens only in some random cases, but only in time periods when ClickHouse server is overloaded with inserts and selects. Hope that helps.

chernser commented 3 months ago

@mih-kopylov Thank you! What is the server version? It may be a retry caused issue.

vietpm commented 3 months ago

@mih-kopylov @vietpm Thanks for reporting!

  1. Do you both use DBeaver?
  2. @vietpm do you have full stack trace?
  3. Does it happen with any query, randomly, only with long running?

Thanks!

Hi, I use DBeaver, it happens with only long running query. There's some heavy query that exceed memory limit, so I try other join algorithms like partial_merge or grace_hash and get the error.

Here's the log from DBeaver:

org.jkiss.dbeaver.model.sql.DBSQLException: SQL Error [216] [07000]: Code: 216. DB::Exception: Query with id = 799583b9-7926-4e56-a9de-309cbd542a1d is already running. (QUERY_WITH_SAME_ID_IS_ALREADY_RUNNING) (version 24.6.1.4423 (official build))

at org.jkiss.dbeaver.model.impl.jdbc.exec.JDBCStatementImpl.executeStatement(JDBCStatementImpl.java:133)

at org.jkiss.dbeaver.ui.editors.sql.execute.SQLQueryJob.executeStatement(SQLQueryJob.java:615)

at org.jkiss.dbeaver.ui.editors.sql.execute.SQLQueryJob.lambda$2(SQLQueryJob.java:506)

at org.jkiss.dbeaver.model.exec.DBExecUtils.tryExecuteRecover(DBExecUtils.java:192)

at org.jkiss.dbeaver.ui.editors.sql.execute.SQLQueryJob.executeSingleQuery(SQLQueryJob.java:525)

at org.jkiss.dbeaver.ui.editors.sql.execute.SQLQueryJob.extractData(SQLQueryJob.java:977)

at org.jkiss.dbeaver.ui.editors.sql.SQLEditor$QueryResultsContainer.readData(SQLEditor.java:4184)

at org.jkiss.dbeaver.ui.controls.resultset.ResultSetJobDataRead.lambda$0(ResultSetJobDataRead.java:128)

at org.jkiss.dbeaver.model.exec.DBExecUtils.tryExecuteRecover(DBExecUtils.java:192)

at org.jkiss.dbeaver.ui.controls.resultset.ResultSetJobDataRead.run(ResultSetJobDataRead.java:126)

at org.jkiss.dbeaver.ui.controls.resultset.ResultSetViewer$ResultSetDataPumpJob.run(ResultSetViewer.java:5160)

at org.jkiss.dbeaver.model.runtime.AbstractJob.run(AbstractJob.java:117)

at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)

Caused by: java.sql.SQLException: Code: 216. DB::Exception: Query with id = 799583b9-7926-4e56-a9de-309cbd542a1d is already running. (QUERY_WITH_SAME_ID_IS_ALREADY_RUNNING) (version 24.6.1.4423 (official build))

at com.clickhouse.jdbc.SqlExceptionUtils.handle(SqlExceptionUtils.java:85)

at com.clickhouse.jdbc.SqlExceptionUtils.create(SqlExceptionUtils.java:31)

at com.clickhouse.jdbc.SqlExceptionUtils.handle(SqlExceptionUtils.java:90)

at com.clickhouse.jdbc.internal.ClickHouseStatementImpl.sendRequest(ClickHouseStatementImpl.java:371)

at com.clickhouse.jdbc.internal.ClickHouseStatementImpl.getLastResponse(ClickHouseStatementImpl.java:141)

at com.clickhouse.jdbc.internal.ClickHouseStatementImpl.executeQuery(ClickHouseStatementImpl.java:537)

at com.clickhouse.jdbc.internal.ClickHouseStatementImpl.execute(ClickHouseStatementImpl.java:525)

at org.jkiss.dbeaver.model.impl.jdbc.exec.JDBCStatementImpl.execute(JDBCStatementImpl.java:330)

at org.jkiss.dbeaver.model.impl.jdbc.exec.JDBCStatementImpl.executeStatement(JDBCStatementImpl.java:131)

... 12 more

Caused by: java.io.IOException: Code: 216. DB::Exception: Query with id = 799583b9-7926-4e56-a9de-309cbd542a1d is already running. (QUERY_WITH_SAME_ID_IS_ALREADY_RUNNING) (version 24.6.1.4423 (official build))

at com.clickhouse.client.http.HttpUrlConnectionImpl.checkResponse(HttpUrlConnectionImpl.java:203)

at com.clickhouse.client.http.HttpUrlConnectionImpl.post(HttpUrlConnectionImpl.java:246)

at com.clickhouse.client.http.ClickHouseHttpClient.send(ClickHouseHttpClient.java:201)

at com.clickhouse.client.AbstractClient.execute(AbstractClient.java:280)

at com.clickhouse.client.ClickHouseClientBuilder$Agent.sendOnce(ClickHouseClientBuilder.java:282)

at com.clickhouse.client.ClickHouseClientBuilder$Agent.send(ClickHouseClientBuilder.java:294)

at com.clickhouse.client.ClickHouseClientBuilder$Agent.execute(ClickHouseClientBuilder.java:349)

at com.clickhouse.client.ClickHouseClient.executeAndWait(ClickHouseClient.java:878)

at com.clickhouse.client.ClickHouseRequest.executeAndWait(ClickHouseRequest.java:2154)

at com.clickhouse.jdbc.internal.ClickHouseStatementImpl.sendRequest(ClickHouseStatementImpl.java:362)

... 17 more
joao-zanutto commented 2 months ago

We're having the same issue using clickhouse-java version 0.6.4 with DBeaver version 24.1.5.202408181605.

Issue happens both with long-running and non long-running queries.

org.jkiss.dbeaver.model.sql.DBSQLException: Erro SQL [216] [07000]: Code: 216. DB::Exception: Query with id = e410d5c3-99de-4a73-9d7c-57ca6e947d47 is already running. (QUERY_WITH_SAME_ID_IS_ALREADY_RUNNING) (version 24.6.2.17 (official build))

    at org.jkiss.dbeaver.model.impl.jdbc.exec.JDBCStatementImpl.executeStatement(JDBCStatementImpl.java:133)

    at org.jkiss.dbeaver.ui.editors.sql.execute.SQLQueryJob.executeStatement(SQLQueryJob.java:616)

    at org.jkiss.dbeaver.ui.editors.sql.execute.SQLQueryJob.lambda$2(SQLQueryJob.java:507)

    at org.jkiss.dbeaver.model.exec.DBExecUtils.tryExecuteRecover(DBExecUtils.java:192)

    at org.jkiss.dbeaver.ui.editors.sql.execute.SQLQueryJob.executeSingleQuery(SQLQueryJob.java:526)

    at org.jkiss.dbeaver.ui.editors.sql.execute.SQLQueryJob.extractData(SQLQueryJob.java:986)

    at org.jkiss.dbeaver.ui.editors.sql.SQLEditor$QueryResultsContainer.readData(SQLEditor.java:4221)

    at org.jkiss.dbeaver.ui.controls.resultset.ResultSetJobDataRead.lambda$0(ResultSetJobDataRead.java:128)

    at org.jkiss.dbeaver.model.exec.DBExecUtils.tryExecuteRecover(DBExecUtils.java:192)

    at org.jkiss.dbeaver.ui.controls.resultset.ResultSetJobDataRead.run(ResultSetJobDataRead.java:126)

    at org.jkiss.dbeaver.ui.controls.resultset.ResultSetViewer$ResultSetDataPumpJob.run(ResultSetViewer.java:5160)

    at org.jkiss.dbeaver.model.runtime.AbstractJob.run(AbstractJob.java:117)

    at org.eclipse.core.internal.jobs.Worker.run(Worker.java:63)

Caused by: java.sql.SQLException: Code: 216. DB::Exception: Query with id = e410d5c3-99de-4a73-9d7c-57ca6e947d47 is already running. (QUERY_WITH_SAME_ID_IS_ALREADY_RUNNING) (version 24.6.2.17 (official build))

    at com.clickhouse.jdbc.SqlExceptionUtils.handle(SqlExceptionUtils.java:85)

    at com.clickhouse.jdbc.SqlExceptionUtils.create(SqlExceptionUtils.java:31)

    at com.clickhouse.jdbc.SqlExceptionUtils.handle(SqlExceptionUtils.java:90)

    at com.clickhouse.jdbc.internal.ClickHouseStatementImpl.sendRequest(ClickHouseStatementImpl.java:375)

    at com.clickhouse.jdbc.internal.ClickHouseStatementImpl.getLastResponse(ClickHouseStatementImpl.java:142)

    at com.clickhouse.jdbc.internal.ClickHouseStatementImpl.executeQuery(ClickHouseStatementImpl.java:541)

    at com.clickhouse.jdbc.internal.ClickHouseStatementImpl.execute(ClickHouseStatementImpl.java:529)

    at org.jkiss.dbeaver.model.impl.jdbc.exec.JDBCStatementImpl.execute(JDBCStatementImpl.java:330)

    at org.jkiss.dbeaver.model.impl.jdbc.exec.JDBCStatementImpl.executeStatement(JDBCStatementImpl.java:131)

    ... 12 more

Caused by: java.io.IOException: Code: 216. DB::Exception: Query with id = e410d5c3-99de-4a73-9d7c-57ca6e947d47 is already running. (QUERY_WITH_SAME_ID_IS_ALREADY_RUNNING) (version 24.6.2.17 (official build))

    at com.clickhouse.client.http.HttpUrlConnectionImpl.checkResponse(HttpUrlConnectionImpl.java:203)

    at com.clickhouse.client.http.HttpUrlConnectionImpl.post(HttpUrlConnectionImpl.java:246)

    at com.clickhouse.client.http.ClickHouseHttpClient.send(ClickHouseHttpClient.java:201)

    at com.clickhouse.client.AbstractClient.sendAsync(AbstractClient.java:161)

    at com.clickhouse.client.AbstractClient.lambda$execute$0(AbstractClient.java:273)

    at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(Unknown Source)

    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)

    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)

    at java.base/java.lang.Thread.run(Unknown Source)
chernser commented 2 months ago

@joao-zanutto thank you for reporting! We had a fix to solve a concurrent issue while copying internal structures. I will re-iterate the investigation.