Timeout exceeded: elapsed 18446744073.709553 seconds #29154
Description
Describe the unexpected behaviour
Recently, all of a sudden, I received such exceptions from different users with different queries that Timeout exceeded: elapsed 18446744073.709553 seconds, maximum: 600 while these queries actually elapsed just about 100ms.
Some fields from system.query_log:
┌──────────event_time─┬─type─────────────────────┬─initial_user─┬─query_duration_ms─┬─memory_usage─┬─read_rows─┬─read_bytes─┬─initial_query_id──────────────────────────────────────────────────────┬─exception──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┬─exception_code─┐
│ 2021-09-16 10:57:37 │ QueryStart │ some_user │ 0 │ 0 │ 0 │ 0 │ 9f2efcbd-ad1e-426f-bef7-8856f243f60f_99775fdd09b0f63dc31f4759a5d19bb3 │ │ 0 │
│ 2021-09-16 10:57:37 │ ExceptionWhileProcessing │ some_user │ 103 │ 0 │ 0 │ 0 │ 9f2efcbd-ad1e-426f-bef7-8856f243f60f_99775fdd09b0f63dc31f4759a5d19bb3 │ Code: 159, e.displayText() = DB::Exception: Timeout exceeded: elapsed 18446744073.709553 seconds, maximum: 600: While executing Remote (version 20.12.9.1) │ 159 │
└─────────────────────┴──────────────────────────┴──────────────┴───────────────────┴──────────────┴───────────┴────────────┴───────────────────────────────────────────────────────────────────────┴────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┴────────────────┘
How to reproduce
- ClickHouse version: 20.12.8.5 ( I manually built image of 20.12.9.1 based on 20.12.8.5 )
- The query itself was expected to elapse very fast. We did have settings of
max_execution_time=600andtimeout_before_checking_execution_speed=10but the exception indicatedelapsed 18446744073.709553 secondswhich was not true. And you can see from the fieldsevent_timeandquery_duration_msthat it actually elapsed 103ms. - What's wired was that other queries from other users threw same exception with exact
elapsed 18446744073.709553 secondsmessage. I wonder where did18446744073.709553 secondscome from? Is it something related to a bug? - I believe query patterns had no impact to this situation because different queries have same timeout exceptions.
- I thought it could be related to my cluster situation but around the time of that exact exception there are many successfully executed same queries.
Expected behavior
The timeout exception should not be thrown if the query didn't elapse longer than max_execution_time. At least the message of timeout exceeded should be correct. I don't know where the 18446744073.709553 seconds comes from.
Error message and/or stacktrace
Code: 159, e.displayText() = DB::Exception: Timeout exceeded: elapsed 18446744073.709553 seconds, maximum: 600: While executing Remote (version 20.12.9.1)