Performance Issue in ClickHouseBulkCopy #153

mbtolou · 2022-07-19T08:11:57Z

The driver for .net (.NET client for ClickHouse) (https://github.com/DarkWanderer/ClickHouse.Client) performs a select operation whenever there is a BulkCopy request (

ClickHouse.Client/ClickHouse.Client/Copy/ClickHouseBulkCopy.cs

Line 103 in 4794942

    
           using (var reader = (ClickHouseDataReader)await connection.ExecuteReaderAsync($"SELECT {GetColumnsExpression(columns)} FROM {DestinationTableName} LIMIT 0").ConfigureAwait(false))

), The consequence of this is an unnecessary increase of the execution time.

Suggested solution:

1 - Is it possible that in line 103 (

ClickHouse.Client/ClickHouse.Client/Copy/ClickHouseBulkCopy.cs

Line 103 in 4794942

    
           using (var reader = (ClickHouseDataReader)await connection.ExecuteReaderAsync($"SELECT {GetColumnsExpression(columns)} FROM {DestinationTableName} LIMIT 0").ConfigureAwait(false))

) provide the option for types to be declared by the developer, and only perform the select ($"SELECT {GetColumnsExpression(columns)} FROM {DestinationTableName} LIMIT 0")) line in the absence of provided types. (Making it possible for the developer to insert the types instead of doing a lookup to find them)

2 - It is also possible to perform the select operation using the following syntax:

select c1,c2,c3,c4,c5,c6,c7,c8,c9,c10,c11
from
  db.data_for_users
where
  (1 = 0);

Performing the following select syntax

select c1,c2,c3,c4,c5,c6,c7,c8,c9,c10,c11
from
  db.data_for_users
where
  limit 0;

Takes ~2000(ms) to be completed, while the following syntax as an alternative:

select c1,c2,c3,c4,c5,c6,c7,c8,c9,c10,c11
from
  db.data_for_users
where
  (1 = 0);

Takes only 15-25 (ms) to be completed. How can this huge time difference be alleviated?

which seems to perform the select operation much faster compared to the limit 0 syntax.

DarkWanderer · 2022-08-02T20:57:06Z

1 - Is it possible that in line 103 (....) provide the option for types to be declared by the developer, and only perform the select ($"SELECT {GetColumnsExpression(columns)} FROM {DestinationTableName} LIMIT 0")) line in the absence of provided types. (Making it possible for the developer to insert the types instead of doing a lookup to find them)

I don't think this makes a lot of sense as the types need to match exactly, otherwise ClickHouse will not be able to parse them (due to the way CH binary format works). I can certainly think about caching the SELECT operation result within BulkCopy object

Takes only 15-25 (ms) to be completed. How can this huge time difference be alleviated?

I can change LIMIT 0 to WHERE 1=0 - are you sure however this is faster in all cases?

mbtolou · 2022-08-03T04:54:26Z

For where 1=1
10.0.0.138:9000, queries 1000, 🔴QPS: 28.922, RPS: 0.000, MiB/s: 0.000, result RPS: 0.000, result MiB/s: 0.000.

0.000% 0.024 sec.
10.000% 0.033 sec.
20.000% 0.033 sec.
30.000% 0.034 sec.
40.000% 0.034 sec.
50.000% 0.034 sec.
60.000% 0.034 sec.
70.000% 0.035 sec.
80.000% 0.035 sec.
90.000% 0.036 sec.
95.000% 0.038 sec.
99.000% 0.046 sec.
99.900% 0.081 sec.
99.990% 0.111 sec.

For limit 0
Queries executed: 1000.

10.0.0.138:9000, queries 1000, 🔵QPS: 4.252, RPS: 0.000, MiB/s: 0.000, result RPS: 0.000, result MiB/s: 0.000.

0.000% 0.199 sec.
10.000% 0.209 sec.
20.000% 0.212 sec.
30.000% 0.215 sec.
40.000% 0.218 sec.
50.000% 0.221 sec.
60.000% 0.225 sec.
70.000% 0.237 sec.
80.000% 0.251 sec.
90.000% 0.280 sec.
95.000% 0.312 sec.
99.000% 0.367 sec.
99.900% 0.468 sec.
99.990% 0.791 sec.

Suggestion: while as you mentioned, considering how the comparison engine of ClickHouse works under the hood, by making this input optional, you can give the user the warning that they need to be careful about the type matches (and as the developer they need to use the right type) and consequently they should handle any exceptions that might occur in the code themselves in case they use the wrong type.

The following picture is the report for such a query on database for the last four months, and as you can see it has taken near 20 hours of processor time, 2m+ times querying the DB, and when the DB is under heavy load it has taken 610+ ms.

Here you can see a few samples that it has taken a long time to perform SELECT on the databse.

Also, is it really necessary to lookup the version for the database each time you query the DB? Wouldn't it yield higher DB performance if you used a static variable to lookup the DB version just one time and store it in that?

DarkWanderer · 2022-08-03T08:49:52Z

Thank you for performance comparison - I will change the selection criteria then

SELECT version() us used when opening new connection to determine which features the server supports. If you have a lot of these, it may be beneficial to keep connection objects for longer

P.S. maybe I can also cache table structure in BulkCopy object itself, will see

mbtolou · 2022-08-03T08:58:42Z

I will change the selection criteria then

thank.
Can't you determine features the first time you connect?

mbtolou · 2022-08-09T02:52:24Z

thank.

mbtolou · 2022-08-18T06:51:16Z

Thank you for performance comparison - I will change the selection criteria then

SELECT version() us used when opening new connection to determine which features the server supports. If you have a lot of these, it may be beneficial to keep connection objects for longer

P.S. maybe I can also cache table structure in BulkCopy object itself, will see

According to your suggestion, I used static connection to inject data in the database.
But I ran into a strange problem.
My connection encounters an error once every few times of use.
I will explain my proposal in several parts:

For the connection, define a version tag in the connection to avoid additional requests to get the version.
I can keep the ClickHouseBulkCopy class static to avoid extra requests to get column names and types.

Currently, two additional requests are sent to the server for each BulkInsert:
Reading the version and getting the list of columns and their types
@DarkWanderer

⌚ 2022-08-17 00:05:53 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 00:30:44 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 00:34:56 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 01:51:09 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 02:05:40 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 02:22:17 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 02:47:22 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 05:07:53 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 05:16:24 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 05:46:43 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 06:23:58 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 07:09:43 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 07:19:39 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 08:17:16 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 09:00:56 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 09:45:37 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 11:27:37 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 11:58:36 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 12:35:47 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 12:54:18 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 13:00:29 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 13:35:37 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 15:34:34 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-17 19:29:38 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...
⌚ 2022-08-18 07:02:31 ⏩ [fatl] ⛪ [LogRepository:WriteDataWithBulk:258] ✅ Error Bulk Insert Into Table : ...

Call Stack IS:

⛔ System.AggregateException: One or more errors occurred. (An error occurred while sending the request.)
 ---> System.Net.Http.HttpRequestException: An error occurred while sending the request.
 ---> System.IO.IOException: The response ended prematurely.
   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.DecompressionHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
   at ClickHouse.Client.ADO.ClickHouseCommand.PostSqlQueryAsync(String sqlQuery, CancellationToken token)
   at ClickHouse.Client.ADO.ClickHouseCommand.ExecuteDbDataReaderAsync(CommandBehavior behavior, CancellationToken cancellationToken)
   at ClickHouse.Client.Copy.ClickHouseBulkCopy.WriteToServerAsync(IEnumerable`1 rows, IReadOnlyCollection`1 columns, CancellationToken token)
   --- End of inner exception stack trace ---
   at System.Threading.Tasks.Task.ThrowIfExceptional(Boolean includeTaskCanceledExceptions)
   at System.Threading.Tasks.Task.Wait(Int32 millisecondsTimeout, CancellationToken cancellationToken)
   at System.Threading.Tasks.Task.Wait()

ruslanen · 2023-07-05T15:40:23Z

@mbtolou hi, how did you solve your problem?
I mean error: System.IO.IOException: The response ended prematurely.
It looks like some kind of floating bug. Could you describe, please?

mbtolou · 2023-07-06T04:43:46Z

I could not solve the problem

In version 6.7.1, the problem has decreased.
I thought maybe the problem was solved by the library creator.

I will reopen the issue to report again if it happens.

ruslanen · 2023-07-06T07:12:33Z

@mbtolou Thank you for your answer!
Yes, I had this problem but I can't reproduce it, if any information appears, I will post it here.

DarkWanderer · 2023-07-06T11:38:32Z

Do you use custom HttpClient, HttpClientHandler or IHttpClientFactory @ruslanen? I did indeed take measures to solve this, but it would still be possible to trigger it in certain circumstances

ruslanen · 2023-07-06T12:07:28Z

@DarkWanderer yes, I use my own HttpClient:
Program.cs

  builder.Services.AddHttpClient("DataRefresh", client => client.Timeout = clickHouseConnectionStringBuilder.Timeout)
        .ConfigurePrimaryHttpMessageHandler(() =>
            new HttpClientHandler
            {
                AutomaticDecompression = DecompressionMethods.GZip | DecompressionMethods.Deflate,
            });

For every query I create new ClickHouseConnection:

        var client = _httpClientFactory.CreateClient("DataRefresh");
        var connection = new ClickHouseConnection(_configuration["ClickHouseSettings:ConnectionString"], client);

I use it because I had an error: "Session is locked by concurrent client"
#152

But I have updated ClickHouse.Client recently from 4.2.2 to 6.7.1 and noticed this error System.IO.IOException: The response ended prematurely in logs of my app.

ruslanen · 2023-07-11T10:37:14Z

Stack trace:

Unhandled exception. System.Net.Http.HttpRequestException: An error occurred while sending the request.
 ---> System.IO.IOException: The response ended prematurely.
   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.DecompressionHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
   at ClickHouse.Client.ADO.ClickHouseCommand.PostSqlQueryAsync(String sqlQuery, CancellationToken token)
   at ClickHouse.Client.ADO.ClickHouseCommand.ExecuteNonQueryAsync(CancellationToken cancellationToken)

(still don't have a scenario to reproduce)

DarkWanderer · 2023-07-11T20:43:44Z

Do you hold the connection reference until you read all of the results, or do you pass the results enumerator away while connection, command or reader object lose visibility? If GC collects objects while you read, you might see this issue

ruslanen · 2023-07-13T03:21:31Z

Do you hold the connection reference until you read all of the results, or do you pass the results enumerator away while connection, command or reader object lose visibility? If GC collects objects while you read, you might see this issue

My queries don't read the result from reader (it's just insert or create table queries).
Common scenario:

        var client = _httpClientFactory.CreateClient("DataRefresh");
        var connection = new ClickHouseConnection(_configuration["ClickHouseSettings:ConnectionString"], client);
        await connection.OpenAsync();
        var command = connection.CreateCommand();
        command.CommandText = "create table ... as select ...";
        await command.ExecuteNonQueryAsync();

Btw, @DarkWanderer could you give some advices about cancellation, please?
#329

plewam · 2023-08-23T06:02:07Z

Hi @ruslanen, @DarkWanderer,

I am facing the same issue. Getting this exception as well. In order to get to the bottom of it I implemented a stopwatch and it seems the exception is thrown immediately. After reading some issue reports in this repo I am quite sure the error was always there, however I am only seeing it since version 6.7.1 which fixed an issue with the exception not being thrown correctly. As of now I am creating a new ClickHouseConnection for every Bulk Insert by

using ClickHouseConnection connection = new(this.ConnectionString);
await connection.OpenAsync();

Do you think it would make sense to use a static HttpClient instead? The error reproduction is quite easy for me. I just need to create a high throughput scenario. I am now digging into two directions:

Reduce the network throughput at my server
Investigate multithreading issues

2023-08-22 16:23:21.246579 [ERR] [046_010] HttpRequestException occured after <0> ms. Exception <"System.Net.Http.HttpRequestException: An error occurred while sending the request.
 ---> System.IO.IOException: The response ended prematurely.
   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage , Boolean , CancellationToken )
   --- End of inner exception stack trace ---
   at System.Net.Http.HttpConnection.SendAsyncCore(HttpRequestMessage , Boolean , CancellationToken )
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage , Boolean , Boolean , CancellationToken )
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage , Boolean , CancellationToken )
   at System.Net.Http.DecompressionHandler.SendAsync(HttpRequestMessage , Boolean , CancellationToken )
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage , HttpCompletionOption , CancellationTokenSource , Boolean , CancellationTokenSource , CancellationToken )
   at ClickHouse.Client.ADO.ClickHouseCommand.PostSqlQueryAsync(String sqlQuery, CancellationToken token)
   at ClickHouse.Client.ADO.ClickHouseCommand.ExecuteDbDataReaderAsync(CommandBehavior behavior, CancellationToken cancellationToken)
   at ClickHouse.Client.Copy.ClickHouseBulkCopy.WriteToServerAsync(IEnumerable`1 rows, IReadOnlyCollection`1 columns, CancellationToken token)
   at Dft.Inside.Lib.ClickHouse.ClickHouseConn.Insert(IDataAgentEntity[] entities, Type type) in D:\DftInternalCollection\Inside\trunk\source\Dft.Inside.Lib.ClickHouse\ClickHouseConn.cs:line 289">

DarkWanderer added the enhancement New feature or request label Aug 2, 2022

DarkWanderer added a commit that referenced this issue Aug 6, 2022

Use WHERE 1=0 instead of LIMIT 0 in BulkCopy #153

d8c1588

DarkWanderer added a commit that referenced this issue Aug 6, 2022

Use WHERE 1=0 instead of LIMIT 0 in BulkCopy #153 (#166)

d2e1e76

mbtolou closed this as completed Aug 10, 2022

mbtolou reopened this Aug 18, 2022

mbtolou closed this as completed Jul 5, 2023

mbtolou reopened this Jul 6, 2023

mbtolou closed this as completed Nov 17, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Performance Issue in ClickHouseBulkCopy #153

Performance Issue in ClickHouseBulkCopy #153

mbtolou commented Jul 19, 2022

DarkWanderer commented Aug 2, 2022

mbtolou commented Aug 3, 2022 •

edited

Loading

DarkWanderer commented Aug 3, 2022 •

edited

Loading

mbtolou commented Aug 3, 2022 •

edited

Loading

mbtolou commented Aug 9, 2022 •

edited

Loading

mbtolou commented Aug 18, 2022 •

edited

Loading

ruslanen commented Jul 5, 2023

mbtolou commented Jul 6, 2023 •

edited

Loading

ruslanen commented Jul 6, 2023

DarkWanderer commented Jul 6, 2023

ruslanen commented Jul 6, 2023 •

edited

Loading

ruslanen commented Jul 11, 2023

DarkWanderer commented Jul 11, 2023

ruslanen commented Jul 13, 2023 •

edited

Loading

plewam commented Aug 23, 2023

Performance Issue in ClickHouseBulkCopy #153

Performance Issue in ClickHouseBulkCopy #153

Comments

mbtolou commented Jul 19, 2022

DarkWanderer commented Aug 2, 2022

mbtolou commented Aug 3, 2022 • edited Loading

DarkWanderer commented Aug 3, 2022 • edited Loading

mbtolou commented Aug 3, 2022 • edited Loading

mbtolou commented Aug 9, 2022 • edited Loading

mbtolou commented Aug 18, 2022 • edited Loading

ruslanen commented Jul 5, 2023

mbtolou commented Jul 6, 2023 • edited Loading

ruslanen commented Jul 6, 2023

DarkWanderer commented Jul 6, 2023

ruslanen commented Jul 6, 2023 • edited Loading

ruslanen commented Jul 11, 2023

DarkWanderer commented Jul 11, 2023

ruslanen commented Jul 13, 2023 • edited Loading

plewam commented Aug 23, 2023

mbtolou commented Aug 3, 2022 •

edited

Loading

DarkWanderer commented Aug 3, 2022 •

edited

Loading

mbtolou commented Aug 3, 2022 •

edited

Loading

mbtolou commented Aug 9, 2022 •

edited

Loading

mbtolou commented Aug 18, 2022 •

edited

Loading

mbtolou commented Jul 6, 2023 •

edited

Loading

ruslanen commented Jul 6, 2023 •

edited

Loading

ruslanen commented Jul 13, 2023 •

edited

Loading