Skip to content

DB::KeyCondition::mayBeTrueInRange() is a bottleneck in a PK lookup #11564

Closed
Closed
DB::KeyCondition::mayBeTrueInRange() is a bottleneck in a PK lookup#11564
Assignees
CurtizJ
Labels
performance
@bobrik

Description

@bobrik
bobrik
opened on Jun 10, 2020

I'm trying to make "last X things" query work reasonably fast on different ranges.

My schema can be reduced to:

CREATE TABLE jaeger_index_v2 (
  timestamp DateTime CODEC(Delta, ZSTD(1)),
  antiTimestamp Int64 MATERIALIZED -toUnixTimestamp(timestamp) CODEC(Delta, ZSTD(1)),
  traceID String CODEC(ZSTD(1)),
  service LowCardinality(String) CODEC(ZSTD(1))
) ENGINE MergeTree()
PARTITION BY toDate(toDateTime(-antiTimestamp))
ORDER BY (service, antiTimestamp)
SETTINGS index_granularity=1024

In #11541 you can find the reasoning behind antiTimestamp, but here it's only important that the primary key of my table is (service, antiTimestamp).

There are two queries I'm interested in:

  • Last 10 unique traceID, 1h window: ~0.6s runtime.
SELECT DISTINCT traceID
  FROM jaeger_index_v2
 WHERE service = 'nginx-fl'
   AND antiTimestamp <= -toUnixTimestamp(now() - 3600)
   AND antiTimestamp >= -toUnixTimestamp(now())
 ORDER BY service,
          antiTimestamp
 LIMIT 10
Trace output 
$ echo "SELECT DISTINCT traceID FROM jaeger_index_v2 PREWHERE service = 'nginx-fl' AND antiTimestamp between -toUnixTimestamp(now()) and -toUnixTimestamp(now() - 3600) ORDER BY service, antiTimestamp LIMIT 10" | docker exec -i clickhouse-jaeger clickhouse-client --send_logs_level=trace --database jaeger
[36ssds310] 2020.06.10 04:06:19.119444 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Debug> executeQuery: (from 127.0.0.1:61902) SELECT DISTINCT traceID FROM jaeger_index_v2 PREWHERE (service = 'nginx-fl') AND ((antiTimestamp >= (-toUnixTimestamp(now()))) AND (antiTimestamp <= (-toUnixTimestamp(now() - 3600)))) ORDER BY service ASC, antiTimestamp ASC LIMIT 10
[36ssds310] 2020.06.10 04:06:19.121585 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> ContextAccess (default): Access granted: SELECT(antiTimestamp, traceID, service) ON jaeger.jaeger_index_v2
[36ssds310] 2020.06.10 04:06:19.122545 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Debug> jaeger.jaeger_index_v2 (SelectExecutor): Key condition: (column 0 in ['nginx-fl', 'nginx-fl']), (column 1 in [-1591761979, +inf)), (column 1 in (-inf, -1591758379]), and, and
[36ssds310] 2020.06.10 04:06:19.122590 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Debug> jaeger.jaeger_index_v2 (SelectExecutor): MinMax index condition: unknown, (column 0 in [-1591761979, +inf)), (column 0 in (-inf, -1591758379]), and, and
[36ssds310] 2020.06.10 04:06:19.494531 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Debug> jaeger.jaeger_index_v2 (SelectExecutor): Selected 29 parts by date, 29 parts by key, 250017 marks to read from 29 ranges
[36ssds310] 2020.06.10 04:06:19.494785 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 3 ranges from part 20200610_1299820_1299820_0, approx. 6144, up to 6144 rows starting from 4096
[36ssds310] 2020.06.10 04:06:19.494864 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 3 ranges from part 20200610_1299819_1299819_0, approx. 6144, up to 6144 rows starting from 4096
[36ssds310] 2020.06.10 04:06:19.494933 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 3 ranges from part 20200610_1299818_1299818_0, approx. 5120, up to 5120 rows starting from 4096
[36ssds310] 2020.06.10 04:06:19.495000 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 3 ranges from part 20200610_1299817_1299817_0, approx. 6144, up to 6144 rows starting from 3072
[36ssds310] 2020.06.10 04:06:19.495066 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 5 ranges from part 20200610_1299811_1299816_1, approx. 30720, up to 30720 rows starting from 25600
[36ssds310] 2020.06.10 04:06:19.495132 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 5 ranges from part 20200610_1299805_1299810_1, approx. 30720, up to 30720 rows starting from 25600
[36ssds310] 2020.06.10 04:06:19.495191 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 5 ranges from part 20200610_1299799_1299804_1, approx. 31744, up to 31744 rows starting from 23552
[36ssds310] 2020.06.10 04:06:19.495254 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 6 ranges from part 20200610_1299793_1299798_1, approx. 32768, up to 32768 rows starting from 23552
[36ssds310] 2020.06.10 04:06:19.495320 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 7 ranges from part 20200610_1299776_1299792_2, approx. 89088, up to 89088 rows starting from 68608
[36ssds310] 2020.06.10 04:06:19.495391 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1299716_1299775_3, approx. 299008, up to 299008 rows starting from 252928
[36ssds310] 2020.06.10 04:06:19.495456 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1299660_1299715_3, approx. 279552, up to 279552 rows starting from 238592
[36ssds310] 2020.06.10 04:06:19.495531 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1299609_1299659_3, approx. 247808, up to 247808 rows starting from 224256
[36ssds310] 2020.06.10 04:06:19.495602 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1299547_1299608_3, approx. 325632, up to 325632 rows starting from 241664
[36ssds310] 2020.06.10 04:06:19.495669 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1299310_1299546_4, approx. 1239040, up to 1239040 rows starting from 940032
[36ssds310] 2020.06.10 04:06:19.496741 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1299122_1299309_4, approx. 952320, up to 952320 rows starting from 780288
[36ssds310] 2020.06.10 04:06:19.496813 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1298940_1299121_4, approx. 903168, up to 903168 rows starting from 778240
[36ssds310] 2020.06.10 04:06:19.496892 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1298881_1298939_3, approx. 289792, up to 289792 rows starting from 256000
[36ssds310] 2020.06.10 04:06:19.496957 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1298776_1298880_4, approx. 500736, up to 500736 rows starting from 474112
[36ssds310] 2020.06.10 04:06:19.497020 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1298726_1298775_3, approx. 260096, up to 260096 rows starting from 200704
[36ssds310] 2020.06.10 04:06:19.497084 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1298501_1298725_4, approx. 1156096, up to 1156096 rows starting from 917504
[36ssds310] 2020.06.10 04:06:19.497140 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1298318_1298500_4, approx. 925696, up to 925696 rows starting from 761856
[36ssds310] 2020.06.10 04:06:19.497204 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1298064_1298317_4, approx. 1274880, up to 1274880 rows starting from 1070080
[36ssds310] 2020.06.10 04:06:19.497278 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1296990_1298063_5, approx. 1775616, up to 1775616 rows starting from 4359168
[36ssds310] 2020.06.10 04:06:19.497530 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1296990_1298063_5, approx. 3749888, up to 3749888 rows starting from 6134784
[36ssds310] 2020.06.10 04:06:19.497622 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1295858_1296989_5, approx. 5734400, up to 5734400 rows starting from 4700160
[36ssds310] 2020.06.10 04:06:19.497722 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1294629_1295857_5, approx. 1183744, up to 1183744 rows starting from 5324800
[36ssds310] 2020.06.10 04:06:19.497833 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1294629_1295857_5, approx. 4847616, up to 4847616 rows starting from 6508544
[36ssds310] 2020.06.10 04:06:19.497904 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1293763_1294628_5, approx. 4402176, up to 4402176 rows starting from 3566592
[36ssds310] 2020.06.10 04:06:19.497976 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1287217_1293762_7, approx. 1418240, up to 1418240 rows starting from 26479616
[36ssds310] 2020.06.10 04:06:19.498064 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1287217_1293762_7, approx. 10668032, up to 10668032 rows starting from 27897856
[36ssds310] 2020.06.10 04:06:19.498142 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1287217_1293762_7, approx. 10668032, up to 10668032 rows starting from 38565888
[36ssds310] 2020.06.10 04:06:19.498254 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1287217_1293762_7, approx. 10668032, up to 10668032 rows starting from 49233920
[36ssds310] 2020.06.10 04:06:19.498327 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1287217_1293762_7, approx. 328704, up to 328704 rows starting from 59901952
[36ssds310] 2020.06.10 04:06:19.498396 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1262566_1287216_7, approx. 10339328, up to 10339328 rows starting from 98164736
[36ssds310] 2020.06.10 04:06:19.498527 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1262566_1287216_7, approx. 10668032, up to 10668032 rows starting from 108504064
[36ssds310] 2020.06.10 04:06:19.498631 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1262566_1287216_7, approx. 10668032, up to 10668032 rows starting from 119172096
[36ssds310] 2020.06.10 04:06:19.498732 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1262566_1287216_7, approx. 10668032, up to 10668032 rows starting from 129840128
[36ssds310] 2020.06.10 04:06:19.498847 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1262566_1287216_7, approx. 10668032, up to 10668032 rows starting from 140508160
[36ssds310] 2020.06.10 04:06:19.498946 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1262566_1287216_7, approx. 10668032, up to 10668032 rows starting from 151176192
[36ssds310] 2020.06.10 04:06:19.499049 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1262566_1287216_7, approx. 10668032, up to 10668032 rows starting from 161844224
[36ssds310] 2020.06.10 04:06:19.499142 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1262566_1287216_7, approx. 10668032, up to 10668032 rows starting from 172512256
[36ssds310] 2020.06.10 04:06:19.499232 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1262566_1287216_7, approx. 10668032, up to 10668032 rows starting from 183180288
[36ssds310] 2020.06.10 04:06:19.499332 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1262566_1287216_7, approx. 10668032, up to 10668032 rows starting from 193848320
[36ssds310] 2020.06.10 04:06:19.499413 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1262566_1287216_7, approx. 10668032, up to 10668032 rows starting from 204516352
[36ssds310] 2020.06.10 04:06:19.499520 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1262566_1287216_7, approx. 10668032, up to 10668032 rows starting from 215184384
[36ssds310] 2020.06.10 04:06:19.499614 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1262566_1287216_7, approx. 654336, up to 654336 rows starting from 225852416
[36ssds310] 2020.06.10 04:06:19.499714 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1237164_1262565_7, approx. 10013696, up to 10013696 rows starting from 100039680
[36ssds310] 2020.06.10 04:06:19.499837 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1237164_1262565_7, approx. 10668032, up to 10668032 rows starting from 110053376
[36ssds310] 2020.06.10 04:06:19.499909 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1237164_1262565_7, approx. 10668032, up to 10668032 rows starting from 120721408
[36ssds310] 2020.06.10 04:06:19.499972 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1237164_1262565_7, approx. 10668032, up to 10668032 rows starting from 131389440
[36ssds310] 2020.06.10 04:06:19.500045 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1237164_1262565_7, approx. 10668032, up to 10668032 rows starting from 142057472
[36ssds310] 2020.06.10 04:06:19.500124 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1237164_1262565_7, approx. 10652672, up to 10652672 rows starting from 152725504
[36ssds310] 2020.06.10 04:06:19.500242 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
28baf857f540ac76
00e89427a40aed20
24596c03d40a825d
eb766c4f037f10ce
31944fce16174447
b20232192914afc1
95ca0f9b5476c2cb
85b7756978a73254
50653aba8fb888ed
91d9ff11ada4ec47
[36ssds310] 2020.06.10 04:06:19.631431 [ 162 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 4809 rows in 0.13 sec., 36991.24 rows/sec., 66.58 MB/sec.
[36ssds310] 2020.06.10 04:06:19.631598 [ 162 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 63488 rows in 0.13 sec., 473777.43 rows/sec., 28.15 MB/sec.
[36ssds310] 2020.06.10 04:06:19.631693 [ 162 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 63488 rows in 0.13 sec., 473777.43 rows/sec., 28.15 MB/sec.
[36ssds310] 2020.06.10 04:06:19.631807 [ 162 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 63488 rows in 0.13 sec., 480955.87 rows/sec., 28.58 MB/sec.
[36ssds310] 2020.06.10 04:06:19.638128 [ 129 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 150059 rows in 0.14 sec., 1064217.64 rows/sec., 61.38 MB/sec.
[36ssds310] 2020.06.10 04:06:19.639514 [ 181 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Debug> MergingSortedTransform: Merge sorted 1 blocks, 109214 rows in 0.14 sec., 769090.57 rows/sec., 30.47 MB/sec.
[36ssds310] 2020.06.10 04:06:19.642601 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Information> executeQuery: Read 3196448 rows, 103.71 MiB in 0.523 sec., 6111478 rows/sec., 198.29 MiB/sec.
[36ssds310] 2020.06.10 04:06:19.642791 [ 134 ] {dd4074bc-33da-423e-a41d-df287f86e280} <Debug> MemoryTracker: Peak memory usage (for query): 214.62 MiB.
  • Last 10 unique traceID, 24h window: ~9.5s runtime.
SELECT DISTINCT traceID
  FROM jaeger_index_v2
 WHERE service = 'nginx-fl'
   AND antiTimestamp <= -toUnixTimestamp(now() - 3600 * 24)
   AND antiTimestamp >= -toUnixTimestamp(now())
 ORDER BY service,
          antiTimestamp
 LIMIT 10
Trace output 
$ echo "SELECT DISTINCT traceID FROM jaeger_index_v2 PREWHERE service = 'nginx-fl' AND antiTimestamp between -toUnixTimestamp(now()) and -toUnixTimestamp(now() - 3600 * 24) ORDER BY service, antiTimestamp LIMIT 10" | docker exec -i clickhouse-jaeger clickhouse-client --send_logs_level=trace --database jaeger
[36ssds310] 2020.06.10 04:07:14.361998 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> executeQuery: (from 127.0.0.1:62214) SELECT DISTINCT traceID FROM jaeger_index_v2 PREWHERE (service = 'nginx-fl') AND ((antiTimestamp >= (-toUnixTimestamp(now()))) AND (antiTimestamp <= (-toUnixTimestamp(now() - (3600 * 24))))) ORDER BY service ASC, antiTimestamp ASC LIMIT 10
[36ssds310] 2020.06.10 04:07:14.371332 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> ContextAccess (default): Access granted: SELECT(antiTimestamp, traceID, service) ON jaeger.jaeger_index_v2
[36ssds310] 2020.06.10 04:07:14.373382 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> jaeger.jaeger_index_v2 (SelectExecutor): Key condition: (column 0 in ['nginx-fl', 'nginx-fl']), (column 1 in [-1591762034, +inf)), (column 1 in (-inf, -1591675634]), and, and
[36ssds310] 2020.06.10 04:07:14.373459 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> jaeger.jaeger_index_v2 (SelectExecutor): MinMax index condition: unknown, (column 0 in [-1591762034, +inf)), (column 0 in (-inf, -1591675634]), and, and
[36ssds310] 2020.06.10 04:07:22.660561 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> jaeger.jaeger_index_v2 (SelectExecutor): Selected 53 parts by date, 50 parts by key, 6756938 marks to read from 50 ranges
[36ssds310] 2020.06.10 04:07:22.660811 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 3 ranges from part 20200610_1300555_1300555_0, approx. 6144, up to 6144 rows starting from 3072
[36ssds310] 2020.06.10 04:07:22.660906 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 3 ranges from part 20200610_1300554_1300554_0, approx. 6144, up to 6144 rows starting from 4096
[36ssds310] 2020.06.10 04:07:22.660990 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 3 ranges from part 20200610_1300553_1300553_0, approx. 5120, up to 5120 rows starting from 4096
[36ssds310] 2020.06.10 04:07:22.661063 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 3 ranges from part 20200610_1300552_1300552_0, approx. 6144, up to 6144 rows starting from 4096
[36ssds310] 2020.06.10 04:07:22.661145 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 5 ranges from part 20200610_1300547_1300551_1, approx. 26624, up to 26624 rows starting from 19456
[36ssds310] 2020.06.10 04:07:22.661228 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 5 ranges from part 20200610_1300541_1300546_1, approx. 31744, up to 31744 rows starting from 24576
[36ssds310] 2020.06.10 04:07:22.661311 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 7 ranges from part 20200610_1300524_1300540_2, approx. 84992, up to 84992 rows starting from 71680
[36ssds310] 2020.06.10 04:07:22.661393 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 7 ranges from part 20200610_1300507_1300523_2, approx. 88064, up to 88064 rows starting from 68608
[36ssds310] 2020.06.10 04:07:22.661465 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1300436_1300506_3, approx. 359424, up to 359424 rows starting from 295936
[36ssds310] 2020.06.10 04:07:22.661559 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1300386_1300435_3, approx. 246784, up to 246784 rows starting from 214016
[36ssds310] 2020.06.10 04:07:22.661644 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1300089_1300385_4, approx. 1539072, up to 1539072 rows starting from 1189888
[36ssds310] 2020.06.10 04:07:22.661725 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 7 ranges from part 20200610_1300072_1300088_2, approx. 89088, up to 89088 rows starting from 68608
[36ssds310] 2020.06.10 04:07:22.661804 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 7 ranges from part 20200610_1300055_1300071_2, approx. 90112, up to 90112 rows starting from 66560
[36ssds310] 2020.06.10 04:07:22.661869 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1300005_1300054_3, approx. 252928, up to 252928 rows starting from 208896
[36ssds310] 2020.06.10 04:07:22.661949 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1299805_1300004_4, approx. 976896, up to 976896 rows starting from 866304
[36ssds310] 2020.06.10 04:07:22.662029 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1299547_1299804_4, approx. 1299456, up to 1299456 rows starting from 1076224
[36ssds310] 2020.06.10 04:07:22.662108 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1299310_1299546_4, approx. 1239040, up to 1239040 rows starting from 940032
[36ssds310] 2020.06.10 04:07:22.662190 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1299122_1299309_4, approx. 952320, up to 952320 rows starting from 780288
[36ssds310] 2020.06.10 04:07:22.662269 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1298940_1299121_4, approx. 903168, up to 903168 rows starting from 778240
[36ssds310] 2020.06.10 04:07:22.662339 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1298881_1298939_3, approx. 289792, up to 289792 rows starting from 256000
[36ssds310] 2020.06.10 04:07:22.662418 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1298776_1298880_4, approx. 500736, up to 500736 rows starting from 474112
[36ssds310] 2020.06.10 04:07:22.662503 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1298726_1298775_3, approx. 260096, up to 260096 rows starting from 200704
[36ssds310] 2020.06.10 04:07:22.662584 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1298501_1298725_4, approx. 1156096, up to 1156096 rows starting from 917504
[36ssds310] 2020.06.10 04:07:22.662668 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1298318_1298500_4, approx. 925696, up to 925696 rows starting from 761856
[36ssds310] 2020.06.10 04:07:22.662733 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1298064_1298317_4, approx. 1274880, up to 1274880 rows starting from 1070080
[36ssds310] 2020.06.10 04:07:22.662813 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1296990_1298063_5, approx. 5525504, up to 5525504 rows starting from 4359168
[36ssds310] 2020.06.10 04:07:22.662892 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1295858_1296989_5, approx. 5734400, up to 5734400 rows starting from 4700160
[36ssds310] 2020.06.10 04:07:22.662979 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1294629_1295857_5, approx. 6031360, up to 6031360 rows starting from 5324800
[36ssds310] 2020.06.10 04:07:22.663065 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1293763_1294628_5, approx. 4402176, up to 4402176 rows starting from 3566592
[36ssds310] 2020.06.10 04:07:22.663130 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1287217_1293762_7, approx. 33751040, up to 33751040 rows starting from 26479616
[36ssds310] 2020.06.10 04:07:22.663218 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1262566_1287216_7, approx. 128343040, up to 128343040 rows starting from 98164736
[36ssds310] 2020.06.10 04:07:22.663338 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1237164_1262565_7, approx. 91898880, up to 91898880 rows starting from 100039680
[36ssds310] 2020.06.10 04:07:22.663804 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1237164_1262565_7, approx. 41167872, up to 41167872 rows starting from 191938560
[36ssds310] 2020.06.10 04:07:22.663931 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1211723_1237163_7, approx. 136497152, up to 136497152 rows starting from 96418816
[36ssds310] 2020.06.10 04:07:22.664029 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1083678_1211722_14, approx. 110631936, up to 110631936 rows starting from 474645504
[36ssds310] 2020.06.10 04:07:22.664144 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1083678_1211722_14, approx. 288296960, up to 288296960 rows starting from 585277440
[36ssds310] 2020.06.10 04:07:22.664222 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200610_1083678_1211722_14, approx. 282084352, up to 282084352 rows starting from 873574400
[36ssds310] 2020.06.10 04:07:22.664299 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 5 ranges from part 20200609_1084082_1283714_1272, approx. 23552, up to 23552 rows starting from 1024
[36ssds310] 2020.06.10 04:07:22.664383 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_1083773_1084080_5, approx. 478208, up to 478208 rows starting from 27648
[36ssds310] 2020.06.10 04:07:22.664463 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_1083650_1083770_3, approx. 418816, up to 418816 rows starting from 151552
[36ssds310] 2020.06.10 04:07:22.664538 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_1083577_1083649_3, approx. 421888, up to 421888 rows starting from 244736
[36ssds310] 2020.06.10 04:07:22.664619 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_1083516_1083576_3, approx. 343040, up to 343040 rows starting from 212992
[36ssds310] 2020.06.10 04:07:22.664701 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_1082407_1083515_5, approx. 4527104, up to 4527104 rows starting from 3988480
[36ssds310] 2020.06.10 04:07:22.664828 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_1082407_1083515_5, approx. 1615872, up to 1615872 rows starting from 8515584
[36ssds310] 2020.06.10 04:07:22.664904 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_1051256_1082406_7, approx. 169789440, up to 169789440 rows starting from 114937856
[36ssds310] 2020.06.10 04:07:22.664994 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_1018668_1051255_7, approx. 116891648, up to 116891648 rows starting from 120051712
[36ssds310] 2020.06.10 04:07:22.665092 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_1018668_1051255_7, approx. 61265920, up to 61265920 rows starting from 236943360
[36ssds310] 2020.06.10 04:07:22.665173 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_875175_1018667_10, approx. 227031040, up to 227031040 rows starting from 520521728
[36ssds310] 2020.06.10 04:07:22.665266 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_875175_1018667_10, approx. 288296960, up to 288296960 rows starting from 747552768
[36ssds310] 2020.06.10 04:07:22.665348 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_875175_1018667_10, approx. 278558720, up to 278558720 rows starting from 1035849728
[36ssds310] 2020.06.10 04:07:22.665432 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_824520_875174_8, approx. 9738240, up to 9738240 rows starting from 176712704
[36ssds310] 2020.06.10 04:07:22.665535 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_824520_875174_8, approx. 277860352, up to 277860352 rows starting from 186450944
[36ssds310] 2020.06.10 04:07:22.665621 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_656996_824519_8, approx. 10436608, up to 10436608 rows starting from 601774080
[36ssds310] 2020.06.10 04:07:22.665709 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_656996_824519_8, approx. 288296960, up to 288296960 rows starting from 612210688
[36ssds310] 2020.06.10 04:07:22.665787 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_656996_824519_8, approx. 288296960, up to 288296960 rows starting from 900507648
[36ssds310] 2020.06.10 04:07:22.665866 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_656996_824519_8, approx. 288296960, up to 288296960 rows starting from 1188804608
[36ssds310] 2020.06.10 04:07:22.665943 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_656996_824519_8, approx. 60943360, up to 60943360 rows starting from 1477101568
[36ssds310] 2020.06.10 04:07:22.666023 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_486578_656995_9, approx. 227353600, up to 227353600 rows starting from 627815424
[36ssds310] 2020.06.10 04:07:22.666125 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_486578_656995_9, approx. 288296960, up to 288296960 rows starting from 855169024
[36ssds310] 2020.06.10 04:07:22.666202 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_486578_656995_9, approx. 288296960, up to 288296960 rows starting from 1143465984
[36ssds310] 2020.06.10 04:07:22.666286 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_486578_656995_9, approx. 132886528, up to 132886528 rows starting from 1431762944
[36ssds310] 2020.06.10 04:07:22.666359 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_350519_486577_9, approx. 155410432, up to 155410432 rows starting from 541052928
[36ssds310] 2020.06.10 04:07:22.666456 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_350519_486577_9, approx. 288296960, up to 288296960 rows starting from 696463360
[36ssds310] 2020.06.10 04:07:22.666544 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_350519_486577_9, approx. 268983296, up to 268983296 rows starting from 984760320
[36ssds310] 2020.06.10 04:07:22.666636 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_234466_350518_8, approx. 19313664, up to 19313664 rows starting from 497026048
[36ssds310] 2020.06.10 04:07:22.666735 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_234466_350518_8, approx. 288296960, up to 288296960 rows starting from 516339712
[36ssds310] 2020.06.10 04:07:22.666811 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_234466_350518_8, approx. 273871872, up to 273871872 rows starting from 804636672
[36ssds310] 2020.06.10 04:07:22.666892 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_122523_234465_9, approx. 14425088, up to 14425088 rows starting from 484709376
[36ssds310] 2020.06.10 04:07:22.666984 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_122523_234465_9, approx. 288296960, up to 288296960 rows starting from 499134464
[36ssds310] 2020.06.10 04:07:22.667049 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_122523_234465_9, approx. 255476736, up to 255476736 rows starting from 787431424
[36ssds310] 2020.06.10 04:07:22.667140 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_1_122522_9, approx. 32820224, up to 32820224 rows starting from 528824320
[36ssds310] 2020.06.10 04:07:22.667235 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_1_122522_9, approx. 288296960, up to 288296960 rows starting from 561644544
[36ssds310] 2020.06.10 04:07:22.667309 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> MergeTreeSelectProcessor: Reading 8 ranges from part 20200609_1_122522_9, approx. 288274432, up to 288274432 rows starting from 849941504
[36ssds310] 2020.06.10 04:07:22.667443 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
1fd36a43b7271902
0033f08e56b858ab
0016ca40f89258c8
a62e14be43cb1c2f
dcb5819b0cc6c229
62fc4f785a0bc041
0ad90f5ca4dce48b
7d76713ce9a7dcc1
feec2152e982d327
a717c839b2d45551
[36ssds310] 2020.06.10 04:07:22.819913 [ 129 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 4785 rows in 0.15 sec., 31479.36 rows/sec., 56.94 MB/sec.
[36ssds310] 2020.06.10 04:07:22.820041 [ 129 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 63488 rows in 0.16 sec., 406962.66 rows/sec., 24.18 MB/sec.
[36ssds310] 2020.06.10 04:07:22.820093 [ 129 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 63488 rows in 0.16 sec., 409588.23 rows/sec., 24.33 MB/sec.
[36ssds310] 2020.06.10 04:07:22.820155 [ 129 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 64512 rows in 0.16 sec., 416194.49 rows/sec., 24.33 MB/sec.
[36ssds310] 2020.06.10 04:07:22.820166 [ 128 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 64512 rows in 0.15 sec., 418897.05 rows/sec., 24.49 MB/sec.
[36ssds310] 2020.06.10 04:07:22.820208 [ 129 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 64512 rows in 0.16 sec., 416194.49 rows/sec., 24.33 MB/sec.
[36ssds310] 2020.06.10 04:07:22.820274 [ 129 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 64512 rows in 0.15 sec., 418897.05 rows/sec., 24.49 MB/sec.
[36ssds310] 2020.06.10 04:07:22.820347 [ 129 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 64512 rows in 0.15 sec., 418897.05 rows/sec., 24.49 MB/sec.
[36ssds310] 2020.06.10 04:07:22.820420 [ 129 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 63488 rows in 0.15 sec., 412247.89 rows/sec., 24.49 MB/sec.
[36ssds310] 2020.06.10 04:07:22.820508 [ 129 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 63488 rows in 0.15 sec., 412247.89 rows/sec., 24.49 MB/sec.
[36ssds310] 2020.06.10 04:07:22.820604 [ 129 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 63488 rows in 0.15 sec., 412247.89 rows/sec., 24.49 MB/sec.
[36ssds310] 2020.06.10 04:07:22.820668 [ 129 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 63488 rows in 0.15 sec., 412247.89 rows/sec., 24.49 MB/sec.
[36ssds310] 2020.06.10 04:07:22.825541 [ 132 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> MergingSortedTransform: Merge sorted 2 blocks, 161712 rows in 0.16 sec., 998193.53 rows/sec., 53.43 MB/sec.
[36ssds310] 2020.06.10 04:07:22.829265 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Information> executeQuery: Read 4963872 rows, 161.06 MiB in 8.467 sec., 586255 rows/sec., 19.02 MiB/sec.
[36ssds310] 2020.06.10 04:07:22.829524 [ 134 ] {6f4693c7-3fd7-4533-85f8-beda82826b49} <Debug> MemoryTracker: Peak memory usage (for query): 341.98 MiB.

Both are supposed to walk the primary key in forward direction and I expect roughly the same performance. In reality there's a significant difference, which largely boils down to this:

image

Pretty much all the time is spent there (look at the time gaps):

[36ssds310] 2020.06.10 04:03:48.248394 [ 134 ] {8f3e3501-e069-4200-b9fd-bc54a04c6065} <Debug> executeQuery: (from 127.0.0.1:60868) SELECT DISTINCT traceID FROM jaeger_index_v2 PREWHERE (service = 'nginx-fl') AND (antiTimestamp <= (-toUnixTimestamp(now() - (3600 * 24)))) AND (antiTimestamp >= (-toUnixTimestamp(now()))) ORDER BY service ASC, antiTimestamp ASC LIMIT 10
...
[36ssds310] 2020.06.10 04:03:48.253344 [ 134 ] {8f3e3501-e069-4200-b9fd-bc54a04c6065} <Debug> jaeger.jaeger_index_v2 (SelectExecutor): MinMax index condition: unknown, (column 0 in (-inf, -1591675428]), and, (column 0 in [-1591761828, +inf)), and
[36ssds310] 2020.06.10 04:03:55.873758 [ 134 ] {8f3e3501-e069-4200-b9fd-bc54a04c6065} <Debug> jaeger.jaeger_index_v2 (SelectExecutor): Selected 47 parts by date, 44 parts by key, 6743228 marks to read from 44 ranges
...
[36ssds310] 2020.06.10 04:03:55.879881 [ 134 ] {8f3e3501-e069-4200-b9fd-bc54a04c6065} <Trace> InterpreterSelectQuery: FetchColumns -> Complete
...
[36ssds310] 2020.06.10 04:03:56.051030 [ 134 ] {8f3e3501-e069-4200-b9fd-bc54a04c6065} <Debug> MemoryTracker: Peak memory usage (for query): 316.84 MiB.

If I trace the function:

$ docker exec -it clickhouse-jaeger objdump -T /usr/bin/clickhouse | fgrep mayBeTrueInRange
0000000009374b50 g    DF .text	000000000000001d  Base        _ZNK2DB12KeyCondition16mayBeTrueInRangeEmPKNS_8FieldRefES3_RKNSt3__16vectorINS4_10shared_ptrIKNS_9IDataTypeEEENS4_9allocatorIS9_EEEE

$ echo _ZNK2DB12KeyCondition16mayBeTrueInRangeEmPKNS_8FieldRefES3_RKNSt3__16vectorINS4_10shared_ptrIKNS_9IDataTypeEEENS4_9allocatorIS9_EEEE | c++filt
DB::KeyCondition::mayBeTrueInRange(unsigned long, DB::FieldRef const*, DB::FieldRef const*, std::__1::vector<std::__1::shared_ptr<DB::IDataType const>, std::__1::allocator<std::__1::shared_ptr<DB::IDataType const> > > const&) const

$ sudo /usr/share/bcc/tools/funccount /state/var/lib/docker/overlay2/8794eb76eb8d76868fc1602075b0d920abece7c257ece060216aeecf23d115de/merged/usr/bin/clickhouse:_ZNK2DB12KeyCondition16mayBeTrueInRangeEmPKNS_8FieldRefES3_RKNSt3__16vectorINS4_10shared_ptrIKNS_9IDataTypeEEENS4_9allocatorIS9_EEEE

I can see that for 1h query it's called 344871 times, while for 24h query it's called 8346350 times, which happens to be 24.2 times more. My understanding is that range selection from a sorted primary key should be a log2 time, not linear, as it appears to be.

I'm on Clickhouse v20.4.4.18-stable, but I'm happy to try any commit.

Metadata

Metadata

Assignees

Labels

performance

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions