bug: http handler will cause query_ids_results invalid

databendlabs / databend

𝗗𝗮𝘁𝗮, 𝗔𝗻𝗮𝗹𝘆𝘁𝗶𝗰𝘀 & 𝗔𝗜. Modern alternative to Snowflake. Cost-effective and simple for massive-scale analytics. https://databend.com

Other

7.74k stars 739 forks source link

SET enable_query_result_cache = 1 0 row read in 0.180 sec. Processed 0 row, 0 B (0 row/s, 0 B/s) :) SET enable_query_result_cache = 1; SET enable_query_result_cache = 1 0 row read in 0.015 sec. Processed 0 row, 0 B (0 row/s, 0 B/s) :) SELECT * FROM t1 ORDER BY a; SELECT * FROM t1 ORDER BY a ┌─────────────────┐ │ a │ │ Nullable(Int32) │ ├─────────────────┤ │ 1 │ │ 2 │ │ 3 │ └─────────────────┘ 3 rows read in 0.102 sec. Processed 3 rows, 13 B (29.46 rows/s, 127 B/s) :) SELECT * FROM RESULT_SCAN(last_query_id()) ORDER BY a; error: APIError: ResponseError with 1016: error: --> SQL:1:15 | 1 | SELECT * FROM RESULT_SCAN(last_query_id()) ORDER BY a | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^ `RESULT_SCAN` failed: No cache key found in current session for query ID '568f96c3-138c-4263-a421-f9c2e91c7418'.

databend-query-default74.2024-01-02-03:{"log_type":1,"handler_type":"HTTPQuery","tenant_id":"default","cluster_id":"default74","node_id":"oZd6I3nONSR5uv0vNztKr7","sql_user":"wubx","query_id":"bd7342d4-7081-41f8-8b73-397e62ead0e5","query_kind":"Update","query_text":"MERGE INTO lz4_0012 USING tmp_8032ca36cc274416b7a58 65af782f68e ON (lz4_0012.n1 = tmp_8032ca36cc274416b7a5865af782f68e.n1) WHEN MATCHED THEN UPDATE SET lz4_0012.s3 = tmp_8032ca36cc274416b7a5865af782f68e.s3, lz4_0012.t3 = tmp_8032ca36cc274416b7a5865af782f68e.t3","event_date":"2024-01-02","event_time":"2024-01-02 03:12:28.595632","query_start_time":"2024-01-02 03:12:28 .580135","query_duration_ms":0,"current_database":"default","databases":"","tables":"","columns":"","projections":"","written_rows":0,"written_bytes":0,"written_io_bytes":0,"written_io_bytes_cost_ms":0,"scan_rows":0,"scan_bytes":0,"scan_io_bytes":0,"scan_io_bytes_cost_ms":0,"scan_partitions":0,"total_partitions":0," result_rows":0,"result_bytes":0,"cpu_usage":2,"memory_usage":0,"join_spilled_bytes":0,"join_spilled_rows":0,"agg_spilled_bytes":0,"agg_spilled_rows":0,"group_by_spilled_bytes":0,"group_by_spilled_rows":0,"client_info":"","client_address":"","user_agent":"Databend JDBC Driver/0.1.4","exception_code":0,"exception_text ":"","stack_trace":"","server_version":"v1.2.271-nightly-0598a77b9c(rust-1.75.0-nightly-2023-12-26T22:05:47.664197474Z)","extra":"","has_profiles":false} databend-query-default74.2024-01-02-03:{"log_type":1,"handler_type":"HTTPQuery","tenant_id":"default","cluster_id":"default74","node_id":"oZd6I3nONSR5uv0vNztKr7","sql_user":"wubx","query_id":"bd7342d4-7081-41f8-8b73-397e62ead0e5","query_kind":"Update","query_text":"MERGE INTO lz4_0012 USING tmp_8032ca36cc274416b7a58 65af782f68e ON (lz4_0012.n1 = tmp_8032ca36cc274416b7a5865af782f68e.n1) WHEN MATCHED THEN UPDATE SET lz4_0012.s3 = tmp_8032ca36cc274416b7a5865af782f68e.s3, lz4_0012.t3 = tmp_8032ca36cc274416b7a5865af782f68e.t3","event_date":"2024-01-02","event_time":"2024-01-02 03:12:28.606933","query_start_time":"2024-01-02 03:12:28 .580135","query_duration_ms":0,"current_database":"default","databases":"","tables":"","columns":"","projections":"","written_rows":0,"written_bytes":0,"written_io_bytes":0,"written_io_bytes_cost_ms":0,"scan_rows":0,"scan_bytes":0,"scan_io_bytes":0,"scan_io_bytes_cost_ms":0,"scan_partitions":0,"total_partitions":0," result_rows":0,"result_bytes":0,"cpu_usage":2,"memory_usage":0,"join_spilled_bytes":0,"join_spilled_rows":0,"agg_spilled_bytes":0,"agg_spilled_rows":0,"group_by_spilled_bytes":0,"group_by_spilled_rows":0,"client_info":"","client_address":"","user_agent":"Databend JDBC Driver/0.1.4","exception_code":0,"exception_text ":"","stack_trace":"","server_version":"v1.2.271-nightly-0598a77b9c(rust-1.75.0-nightly-2023-12-26T22:05:47.664197474Z)","extra":"","has_profiles":false} databend-query-default74.2024-01-02-03:{"log_type":2,"handler_type":"HTTPQuery","tenant_id":"default","cluster_id":"default74","node_id":"oZd6I3nONSR5uv0vNztKr7","sql_user":"wubx","query_id":"bd7342d4-7081-41f8-8b73-397e62ead0e5","query_kind":"Update","query_text":"MERGE INTO lz4_0012 USING tmp_8032ca36cc274416b7a58 65af782f68e ON (lz4_0012.n1 = tmp_8032ca36cc274416b7a5865af782f68e.n1) WHEN MATCHED THEN UPDATE SET lz4_0012.s3 = tmp_8032ca36cc274416b7a5865af782f68e.s3, lz4_0012.t3 = tmp_8032ca36cc274416b7a5865af782f68e.t3","event_date":"2024-01-02","event_time":"2024-01-02 03:12:28.622715","query_start_time":"2024-01-02 03:12:28 .580135","query_duration_ms":42,"current_database":"default","databases":"","tables":"","columns":"","projections":"","written_rows":0,"written_bytes":0,"written_io_bytes":0,"written_io_bytes_cost_ms":0,"scan_rows":10000,"scan_bytes":41250,"scan_io_bytes":0,"scan_io_bytes_cost_ms":0,"scan_partitions":1,"total_partit ions":1,"result_rows":10000,"result_bytes":82500,"cpu_usage":2,"memory_usage":0,"join_spilled_bytes":0,"join_spilled_rows":0,"agg_spilled_bytes":0,"agg_spilled_rows":0,"group_by_spilled_bytes":0,"group_by_spilled_rows":0,"client_info":"","client_address":"","user_agent":"Databend JDBC Driver/0.1.4","exception_code": 0,"exception_text":"","stack_trace":"","server_version":"v1.2.271-nightly-0598a77b9c(rust-1.75.0-nightly-2023-12-26T22:05:47.664197474Z)","extra":"","has_profiles":true} databend-query-default74.2024-01-02-03:{"log_type":2,"handler_type":"HTTPQuery","tenant_id":"default","cluster_id":"default74","node_id":"oZd6I3nONSR5uv0vNztKr7","sql_user":"wubx","query_id":"bd7342d4-7081-41f8-8b73-397e62ead0e5","query_kind":"Update","query_text":"MERGE INTO lz4_0012 USING tmp_8032ca36cc274416b7a58 65af782f68e ON (lz4_0012.n1 = tmp_8032ca36cc274416b7a5865af782f68e.n1) WHEN MATCHED THEN UPDATE SET lz4_0012.s3 = tmp_8032ca36cc274416b7a5865af782f68e.s3, lz4_0012.t3 = tmp_8032ca36cc274416b7a5865af782f68e.t3","event_date":"2024-01-02","event_time":"2024-01-02 03:12:32.063197","query_start_time":"2024-01-02 03:12:28 .580135","query_duration_ms":3483,"current_database":"default","databases":"","tables":"","columns":"","projections":"","written_rows":570000,"written_bytes":54377132,"written_io_bytes":0,"written_io_bytes_cost_ms":0,"scan_rows":620000,"scan_bytes":58684586,"scan_io_bytes":0,"scan_io_bytes_cost_ms":0,"scan_partition s":2,"total_partitions":2,"result_rows":10000,"result_bytes":82500,"cpu_usage":2,"memory_usage":0,"join_spilled_bytes":0,"join_spilled_rows":0,"agg_spilled_bytes":0,"agg_spilled_rows":0,"group_by_spilled_bytes":0,"group_by_spilled_rows":0,"client_info":"","client_address":"","user_agent":"Databend JDBC Driver/0.1.4" ,"exception_code":0,"exception_text":"","stack_trace":"","server_version":"v1.2.271-nightly-0598a77b9c(rust-1.75.0-nightly-2023-12-26T22:05:47.664197474Z)","extra":"","has_profiles":true}

Does it generate same to query id?

This query details log with one query record twice.

databend-query-default74.2024-01-02-03:{"log_type":1,"handler_type":"HTTPQuery","tenant_id":"default","cluster_id":"default74","node_id":"oZd6I3nONSR5uv0vNztKr7","sql_user":"wubx","query_id":"bd7342d4-7081-41f8-8b73-397e62ead0e5","query_kind":"Update","query_text":"MERGE INTO lz4_0012 USING tmp_8032ca36cc274416b7a58
65af782f68e ON (lz4_0012.n1 = tmp_8032ca36cc274416b7a5865af782f68e.n1) WHEN MATCHED THEN UPDATE SET lz4_0012.s3 = tmp_8032ca36cc274416b7a5865af782f68e.s3, lz4_0012.t3 = tmp_8032ca36cc274416b7a5865af782f68e.t3","event_date":"2024-01-02","event_time":"2024-01-02 03:12:28.595632","query_start_time":"2024-01-02 03:12:28
.580135","query_duration_ms":0,"current_database":"default","databases":"","tables":"","columns":"","projections":"","written_rows":0,"written_bytes":0,"written_io_bytes":0,"written_io_bytes_cost_ms":0,"scan_rows":0,"scan_bytes":0,"scan_io_bytes":0,"scan_io_bytes_cost_ms":0,"scan_partitions":0,"total_partitions":0,"
result_rows":0,"result_bytes":0,"cpu_usage":2,"memory_usage":0,"join_spilled_bytes":0,"join_spilled_rows":0,"agg_spilled_bytes":0,"agg_spilled_rows":0,"group_by_spilled_bytes":0,"group_by_spilled_rows":0,"client_info":"","client_address":"","user_agent":"Databend JDBC Driver/0.1.4","exception_code":0,"exception_text
":"","stack_trace":"","server_version":"v1.2.271-nightly-0598a77b9c(rust-1.75.0-nightly-2023-12-26T22:05:47.664197474Z)","extra":"","has_profiles":false}
databend-query-default74.2024-01-02-03:{"log_type":1,"handler_type":"HTTPQuery","tenant_id":"default","cluster_id":"default74","node_id":"oZd6I3nONSR5uv0vNztKr7","sql_user":"wubx","query_id":"bd7342d4-7081-41f8-8b73-397e62ead0e5","query_kind":"Update","query_text":"MERGE INTO lz4_0012 USING tmp_8032ca36cc274416b7a58
65af782f68e ON (lz4_0012.n1 = tmp_8032ca36cc274416b7a5865af782f68e.n1) WHEN MATCHED THEN UPDATE SET lz4_0012.s3 = tmp_8032ca36cc274416b7a5865af782f68e.s3, lz4_0012.t3 = tmp_8032ca36cc274416b7a5865af782f68e.t3","event_date":"2024-01-02","event_time":"2024-01-02 03:12:28.606933","query_start_time":"2024-01-02 03:12:28
.580135","query_duration_ms":0,"current_database":"default","databases":"","tables":"","columns":"","projections":"","written_rows":0,"written_bytes":0,"written_io_bytes":0,"written_io_bytes_cost_ms":0,"scan_rows":0,"scan_bytes":0,"scan_io_bytes":0,"scan_io_bytes_cost_ms":0,"scan_partitions":0,"total_partitions":0,"
result_rows":0,"result_bytes":0,"cpu_usage":2,"memory_usage":0,"join_spilled_bytes":0,"join_spilled_rows":0,"agg_spilled_bytes":0,"agg_spilled_rows":0,"group_by_spilled_bytes":0,"group_by_spilled_rows":0,"client_info":"","client_address":"","user_agent":"Databend JDBC Driver/0.1.4","exception_code":0,"exception_text
":"","stack_trace":"","server_version":"v1.2.271-nightly-0598a77b9c(rust-1.75.0-nightly-2023-12-26T22:05:47.664197474Z)","extra":"","has_profiles":false}
databend-query-default74.2024-01-02-03:{"log_type":2,"handler_type":"HTTPQuery","tenant_id":"default","cluster_id":"default74","node_id":"oZd6I3nONSR5uv0vNztKr7","sql_user":"wubx","query_id":"bd7342d4-7081-41f8-8b73-397e62ead0e5","query_kind":"Update","query_text":"MERGE INTO lz4_0012 USING tmp_8032ca36cc274416b7a58
65af782f68e ON (lz4_0012.n1 = tmp_8032ca36cc274416b7a5865af782f68e.n1) WHEN MATCHED THEN UPDATE SET lz4_0012.s3 = tmp_8032ca36cc274416b7a5865af782f68e.s3, lz4_0012.t3 = tmp_8032ca36cc274416b7a5865af782f68e.t3","event_date":"2024-01-02","event_time":"2024-01-02 03:12:28.622715","query_start_time":"2024-01-02 03:12:28
.580135","query_duration_ms":42,"current_database":"default","databases":"","tables":"","columns":"","projections":"","written_rows":0,"written_bytes":0,"written_io_bytes":0,"written_io_bytes_cost_ms":0,"scan_rows":10000,"scan_bytes":41250,"scan_io_bytes":0,"scan_io_bytes_cost_ms":0,"scan_partitions":1,"total_partit
ions":1,"result_rows":10000,"result_bytes":82500,"cpu_usage":2,"memory_usage":0,"join_spilled_bytes":0,"join_spilled_rows":0,"agg_spilled_bytes":0,"agg_spilled_rows":0,"group_by_spilled_bytes":0,"group_by_spilled_rows":0,"client_info":"","client_address":"","user_agent":"Databend JDBC Driver/0.1.4","exception_code":
0,"exception_text":"","stack_trace":"","server_version":"v1.2.271-nightly-0598a77b9c(rust-1.75.0-nightly-2023-12-26T22:05:47.664197474Z)","extra":"","has_profiles":true}
databend-query-default74.2024-01-02-03:{"log_type":2,"handler_type":"HTTPQuery","tenant_id":"default","cluster_id":"default74","node_id":"oZd6I3nONSR5uv0vNztKr7","sql_user":"wubx","query_id":"bd7342d4-7081-41f8-8b73-397e62ead0e5","query_kind":"Update","query_text":"MERGE INTO lz4_0012 USING tmp_8032ca36cc274416b7a58
65af782f68e ON (lz4_0012.n1 = tmp_8032ca36cc274416b7a5865af782f68e.n1) WHEN MATCHED THEN UPDATE SET lz4_0012.s3 = tmp_8032ca36cc274416b7a5865af782f68e.s3, lz4_0012.t3 = tmp_8032ca36cc274416b7a5865af782f68e.t3","event_date":"2024-01-02","event_time":"2024-01-02 03:12:32.063197","query_start_time":"2024-01-02 03:12:28
.580135","query_duration_ms":3483,"current_database":"default","databases":"","tables":"","columns":"","projections":"","written_rows":570000,"written_bytes":54377132,"written_io_bytes":0,"written_io_bytes_cost_ms":0,"scan_rows":620000,"scan_bytes":58684586,"scan_io_bytes":0,"scan_io_bytes_cost_ms":0,"scan_partition
s":2,"total_partitions":2,"result_rows":10000,"result_bytes":82500,"cpu_usage":2,"memory_usage":0,"join_spilled_bytes":0,"join_spilled_rows":0,"agg_spilled_bytes":0,"agg_spilled_rows":0,"group_by_spilled_bytes":0,"group_by_spilled_rows":0,"client_info":"","client_address":"","user_agent":"Databend JDBC Driver/0.1.4"
,"exception_code":0,"exception_text":"","stack_trace":"","server_version":"v1.2.271-nightly-0598a77b9c(rust-1.75.0-nightly-2023-12-26T22:05:47.664197474Z)","extra":"","has_profiles":true}

No same. details info in this issue. https://github.com/datafuselabs/databend/issues/14172. But it looks like by design. We should start by combing through the http and session logic

databendlabs / databend

bug: http handler will cause query_ids_results invalid #14204

Search before asking

Version

What's Wrong?

How to Reproduce?

Are you willing to submit PR?