DB::Exception: RangeReader read 7523 rows, but 7550 expected..

[doom369]

Query:

SELECT 
         *
     FROM reporting_events
     WHERE (device_id = 51);

Result:

DB::Exception: RangeReader read 7523 rows, but 7550 expected..

Table:

CREATE TABLE reporting_events (
  id UInt64,
  a UInt32,
  b UInt64,
  c UInt32,
  d DEFAULT 0,
  e UInt32 DEFAULT 0,
  device_id UInt32,
  ts DateTime DEFAULT now(),
  name String,
  type Enum8('ONLINE'      = 0,
             'OFFLINE'     = 1,
             'INFORMATION' = 2,
             'WARNING'     = 3,
             'CRITICAL'    = 4),
  description String
)
ENGINE = MergeTree()
PARTITION BY toYYYYMM(ts)
ORDER BY (a, b, e, device_id, ts, type)
TTL ts + INTERVAL 6 MONTH;

Clickhouse version 20.1.2, same with 20.1.3.7. Probably this error due to update to the latest clickhouse version.

[doom369]

Error from the log:

2020.02.03 11:12:35.185941 [ 50 ] {e56d27a0-9040-45e8-b1c2-8f3246dddf26} <Error> executeQuery: Code: 49, e.displayText() = DB::Exception: RangeReader read 7524 rows, but 7551 expected. (version 20.1.3.7 (official build)) (from 127.0.0.1:33204) (in query: SELECT * FROM reporting_events WHERE device_id = 51), Stack trace (when copying this message, always include the lines below):

0. 0xbc3212c Poco::Exception::Exception(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int)  in /usr/bin/clickhouse
1. 0x4f6cbc9 DB::Exception::Exception(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int)  in /usr/bin/clickhouse
2. 0x4cb3235 ?  in /usr/bin/clickhouse
3. 0x97a594f DB::MergeTreeRangeReader::read(unsigned long, std::__1::vector<DB::MarkRange, std::__1::allocator<DB::MarkRange> >&)  in /usr/bin/clickhouse
4. 0x97684c6 DB::MergeTreeBaseSelectProcessor::readFromPartImpl()  in /usr/bin/clickhouse
5. 0x9769cc3 DB::MergeTreeBaseSelectProcessor::generate()  in /usr/bin/clickhouse
6. 0x91a4c87 DB::ISource::work()  in /usr/bin/clickhouse
7. 0x91d6e84 DB::TreeExecutorBlockInputStream::execute()  in /usr/bin/clickhouse
8. 0x91d70a3 DB::TreeExecutorBlockInputStream::readImpl()  in /usr/bin/clickhouse
9. 0x8a6d24f DB::IBlockInputStream::read()  in /usr/bin/clickhouse
10. 0x949c1c8 DB::ExpressionBlockInputStream::readImpl()  in /usr/bin/clickhouse
11. 0x8a6d24f DB::IBlockInputStream::read()  in /usr/bin/clickhouse
12. 0x949c1c8 DB::ExpressionBlockInputStream::readImpl()  in /usr/bin/clickhouse
13. 0x8a6d24f DB::IBlockInputStream::read()  in /usr/bin/clickhouse
14. 0x8c2a6ec DB::ParallelInputsProcessor<DB::UnionBlockInputStream::Handler>::thread(std::__1::shared_ptr<DB::ThreadGroupStatus>, unsigned long)  in /usr/bin/clickhouse
15. 0x8c2b465 ThreadFromGlobalPool::ThreadFromGlobalPool<void (DB::ParallelInputsProcessor<DB::UnionBlockInputStream::Handler>::*)(std::__1::shared_ptr<DB::ThreadGroupStatus>, unsigned long), DB::ParallelInputsProcessor<DB::UnionBlockInputStream::Handler>*, std::__1::shared_ptr<DB::ThreadGroupStatus>, unsigned long&>(void (DB::ParallelInputsProcessor<DB::UnionBlockInputStream::Handler>::*&&)(std::__1::shared_ptr<DB::ThreadGroupStatus>, unsigned long), DB::ParallelInputsProcessor<DB::UnionBlockInputStream::Handler>*&&, std::__1::shared_ptr<DB::ThreadGroupStatus>&&, unsigned long&)::'lambda'()::operator()() const  in /usr/bin/clickhouse
16. 0x4fa3a77 ThreadPoolImpl<std::__1::thread>::worker(std::__1::__list_iterator<std::__1::thread, void*>)  in /usr/bin/clickhouse
17. 0x4fa202f ?  in /usr/bin/clickhouse
18. 0x76db start_thread  in /lib/x86_64-linux-gnu/libpthread-2.27.so
19. 0x12188f clone  in /lib/x86_64-linux-gnu/libc-2.27.so

[CurtizJ]

This bug is very hard to reproduce. It would be great if you could send data parts from table privately to our mailing list clickhouse-feedback@yandex-team.ru or make a reproducible example on synthetic data.

[doom369]

@CurtizJ I can prepare VM with the issue and give you access to it. Would that help?

[CurtizJ]

Yes, it's ok.

[doom369]

@CurtizJ created VM, email sent. Thanks.

[CurtizJ]

I reproduced it by this example:

drop table if exists t;

create table t (a Int, b Int) engine = MergeTree order by (a, b) settings index_granularity = 400;

insert into t select 0, 0 from numbers(50);
insert into t select 0, 1  from numbers(350);
insert into t select 1, 2  from numbers(400);
insert into t select 2, 2  from numbers(400);
insert into t select 3, 0 from numbers(100);

set max_threads=1;
optimize table t final;

select sum(a) from t where a in (0, 3) and b = 0; 

↖ Progress: 0.00 rows, 0.00 B (0.00 rows/s., 0.00 B/s.) Received exception from server (version 20.2.1):
Code: 49. DB::Exception: Received from localhost:9000. DB::Exception: RangeReader read 100 rows, but 150 expected.: While executing MergeTree.

It doesn't work only when MergeTreeSelectProcessor is used instead of MergeTreeThreadSelectProcessor. It's used in several cases: reading in 1 thread, SELECT with FINAL modifier, reading in order of primary key.

[doom369]

@CurtizJ I see, thanks. From what I understand I'm the only one who see this issue is because our test env. using low-end VM with only 1 core (and thus max_threads=1). Interesting. However, those still look like regression introduced in the latest version. Before the update the were no errors. (and we have multiple similar envs).

[CurtizJ]

reading in 1 thread

Only this case was affected.