Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

index join exceeding memory of quota may hang the session #45716

Closed
aytrack opened this issue Aug 1, 2023 · 3 comments · Fixed by #45890
Closed

index join exceeding memory of quota may hang the session #45716

aytrack opened this issue Aug 1, 2023 · 3 comments · Fixed by #45890
Assignees
Labels
affects-5.4 This bug affects the 5.4.x(LTS) versions. affects-6.1 This bug affects the 6.1.x(LTS) versions. affects-6.5 This bug affects the 6.5.x(LTS) versions. affects-7.1 This bug affects the 7.1.x(LTS) versions. severity/major sig/execution SIG execution type/bug The issue is confirmed as a bug.

Comments

@aytrack
Copy link
Contributor

aytrack commented Aug 1, 2023

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. Minimal reproduce step (Required)

set tidb_mem_quota_query = 120000;
drop table if exists t1, t2;
create table t1(a int, index(a));
create table t2(a int, index(a));
insert into t1 values (1), (2);
insert into t2 values (1),(1),(2),(2);
select /*+ inl_join(t2) */ * from t1 join t2 on t1.a = t2.a;
set tidb_mem_quota_query=1000;
select /*+ inl_join(t2) */ * from t1 join t2 on t1.a = t2.a;

2. What did you expect to see? (Required)

report exceed memory quota error

sql > select /*+ inl_join(t2) */ * from t1 join t2 on t1.a = t2.a;
(1105, 'Your query has been cancelled due to exceeding the allowed memory limit for a single SQL query. Please try narrowing your query scope or increase the tidb_mem_quota_query limit and try again.[conn=2097154]')

3. What did you see instead (Required)

the second query for a long time and no reocrd returned. the session maybe hang.

[16:46:45]TiDB root:test> show processlist;
+---------+------+-----------------+------+---------+------+------------+-------------------------------------------------------------+
| Id      | User | Host            | db   | Command | Time | State      | Info                                                        |
+---------+------+-----------------+------+---------+------+------------+-------------------------------------------------------------+
| 2097166 | root | 127.0.0.1:51511 | test | Query   | 105  | autocommit | select /*+ inl_join(t2) */ * from t1 join t2 on t1.a = t2.a |
| 2097168 | root | 127.0.0.1:51517 | test | Query   | 79   | autocommit | select /*+ inl_join(t2) */ * from t1 join t2 on t1.a = t2.a |
| 2097170 | root | 127.0.0.1:51522 | test | Query   | 0    | autocommit | show processlist                                            |
| 2097154 | root | 127.0.0.1:51377 | test | Query   | 403  | autocommit | select /*+ inl_join(t2) */ * from t1 join t2 on t1.a = t2.a |
| 2097156 | root | 127.0.0.1:51385 | test | Sleep   | 389  | autocommit | <null>                                                      |
| 2097162 | root | 127.0.0.1:51448 | test | Query   | 242  | autocommit | select /*+ inl_join(t2) */ * from t1 join t2 on t1.a = t2.a |
| 2097164 | root | 127.0.0.1:51503 | test | Query   | 120  | autocommit | select /*+ inl_join(t2) */ * from t1 join t2 on t1.a = t2.a |
+---------+------+-----------------+------+---------+------+------------+-------------------------------------------------------------+

tidb log

[2023/08/01 16:40:01.970 +08:00] [ERROR] [adapter.go:152] ["execute sql panic"] [conn=2097154] [sql="select /*+ inl_join(t2) */ * from t1 join t2 on t1.a = t2.a"] [stack="github.com/pingcap/tidb/executor.(*recordSet).Next.func1
	/Users/aytrack/gitproject/pingcap/tidb/executor/adapter.go:152
runtime.gopanic
	/opt/homebrew/Cellar/go/1.20.2/libexec/src/runtime/panic.go:884
github.com/pingcap/tidb/util/memory.(*PanicOnExceed).Action
	/Users/aytrack/gitproject/pingcap/tidb/util/memory/action.go:187
github.com/pingcap/tidb/util/memory.(*Tracker).Consume.func1
	/Users/aytrack/gitproject/pingcap/tidb/util/memory/tracker.go:440
github.com/pingcap/tidb/util/memory.(*Tracker).Consume
	/Users/aytrack/gitproject/pingcap/tidb/util/memory/tracker.go:484
github.com/pingcap/tidb/executor.(*IndexLookUpJoin).newInnerWorker
	/Users/aytrack/gitproject/pingcap/tidb/executor/index_lookup_join.go:242
github.com/pingcap/tidb/executor.(*IndexLookUpJoin).startWorkers
	/Users/aytrack/gitproject/pingcap/tidb/executor/index_lookup_join.go:194
github.com/pingcap/tidb/executor.(*IndexLookUpJoin).Next
	/Users/aytrack/gitproject/pingcap/tidb/executor/index_lookup_join.go:261
github.com/pingcap/tidb/executor.Next
	/Users/aytrack/gitproject/pingcap/tidb/executor/executor.go:253
github.com/pingcap/tidb/executor.(*ExecStmt).next
	/Users/aytrack/gitproject/pingcap/tidb/executor/adapter.go:1222
github.com/pingcap/tidb/executor.(*recordSet).Next
	/Users/aytrack/gitproject/pingcap/tidb/executor/adapter.go:155
github.com/pingcap/tidb/server/internal/resultset.(*tidbResultSet).Next
	/Users/aytrack/gitproject/pingcap/tidb/server/internal/resultset/resultset.go:62
github.com/pingcap/tidb/server.(*clientConn).writeChunks
	/Users/aytrack/gitproject/pingcap/tidb/server/conn.go:2207
github.com/pingcap/tidb/server.(*clientConn).writeResultSet
	/Users/aytrack/gitproject/pingcap/tidb/server/conn.go:2150
github.com/pingcap/tidb/server.(*clientConn).handleStmt
	/Users/aytrack/gitproject/pingcap/tidb/server/conn.go:2018
github.com/pingcap/tidb/server.(*clientConn).handleQuery
	/Users/aytrack/gitproject/pingcap/tidb/server/conn.go:1779
github.com/pingcap/tidb/server.(*clientConn).dispatch
	/Users/aytrack/gitproject/pingcap/tidb/server/conn.go:1266
github.com/pingcap/tidb/server.(*clientConn).Run
	/Users/aytrack/gitproject/pingcap/tidb/server/conn.go:1045
github.com/pingcap/tidb/server.(*Server).onConn
	/Users/aytrack/gitproject/pingcap/tidb/server/server.go:662"]
[2023/08/01 16:40:01.970 +08:00] [ERROR] [coprocessor.go:1100] ["copIteratorWork meet panic"] [r="\"Your query has been cancelled due to exceeding the allowed memory limit for a single SQL query. Please try narrowing your query scope or increase the tidb_mem_quota_query limit and try again.[conn=2097154]\""] ["stack trace"="github.com/pingcap/tidb/store/copr.(*copIteratorWorker).handleTask.func1
	/Users/aytrack/gitproject/pingcap/tidb/store/copr/coprocessor.go:1102
runtime.gopanic
	/opt/homebrew/Cellar/go/1.20.2/libexec/src/runtime/panic.go:884
github.com/pingcap/tidb/util/memory.(*PanicOnExceed).Action
	/Users/aytrack/gitproject/pingcap/tidb/util/memory/action.go:187
github.com/pingcap/tidb/util/memory.(*Tracker).Consume.func1
	/Users/aytrack/gitproject/pingcap/tidb/util/memory/tracker.go:440
github.com/pingcap/tidb/util/memory.(*Tracker).Consume
	/Users/aytrack/gitproject/pingcap/tidb/util/memory/tracker.go:484
github.com/pingcap/tidb/store/copr.(*copIteratorWorker).sendToRespCh
	/Users/aytrack/gitproject/pingcap/tidb/store/copr/coprocessor.go:990
github.com/pingcap/tidb/store/copr.(*copIteratorWorker).handleCopResponse
	/Users/aytrack/gitproject/pingcap/tidb/store/copr/coprocessor.go:1401
github.com/pingcap/tidb/store/copr.(*copIteratorWorker).handleCopPagingResult
	/Users/aytrack/gitproject/pingcap/tidb/store/copr/coprocessor.go:1302
github.com/pingcap/tidb/store/copr.(*copIteratorWorker).handleTaskOnce
	/Users/aytrack/gitproject/pingcap/tidb/store/copr/coprocessor.go:1241
github.com/pingcap/tidb/store/copr.(*copIteratorWorker).handleTask
	/Users/aytrack/gitproject/pingcap/tidb/store/copr/coprocessor.go:1113
github.com/pingcap/tidb/store/copr.(*copIteratorWorker).run
	/Users/aytrack/gitproject/pingcap/tidb/store/copr/coprocessor.go:806"]

[2023/08/01 16:47:59.240 +08:00] [WARN] [expensivequery.go:145] [expensive_query] [cost_time=180.150269709s] [stats=t1:443253881867075585,t2:443253881867862019] [conn=2097166] [user=root] [database=test] [index_names="[t1:a]"] [txn_start_ts=443253915409186816] [mem_max="1210 Bytes (1.18 KB)"] [sql="select /*+ inl_join(t2) */ * from t1 join t2 on t1.a = t2.a"]
[2023/08/01 16:48:02.743 +08:00] [WARN] [expensivequery.go:145] [expensive_query] [cost_time=480.772150833s] [stats=t1:pseudo,t2:pseudo] [conn=2097154] [user=root] [database=test] [index_names="[t1:a]"] [txn_start_ts=443253837520961536] [mem_max="1210 Bytes (1.18 KB)"] [sql="select /*+ inl_join(t2) */ * from t1 join t2 on t1.a = t2.a"]
[2023/08/01 16:48:26.240 +08:00] [WARN] [expensivequery.go:145] [expensive_query] [cost_time=180.2530095s] [stats=t2:443253881867862019,t1:443253881867075585] [conn=2097168] [user=root] [database=test] [index_names="[t1:a]"] [txn_start_ts=443253922460598272] [mem_max="1214 Bytes (1.19 KB)"] [sql="select /*+ inl_join(t2) */ * from t1 join t2 on t1.a = t2.a"]

4. What is your TiDB version? (Required)

[16:48:15]TiDB root:test> select tidb_version();
+-----------------------------------------------------------+
| tidb_version()                                            |
+-----------------------------------------------------------+
| Release Version: v7.3.0-alpha-264-g79f0001601             |
| Edition: Community                                        |
| Git Commit Hash: 79f00016016e9a1688613b7f4c8b5d830814fecb |
| Git Branch: HEAD                                          |
| UTC Build Time: 2023-08-01 08:39:18                       |
| GoVersion: go1.20.2                                       |
| Race Enabled: false                                       |
| Check Table Before Drop: false                            |
| Store: unistore                                           |
+-----------------------------------------------------------+
@aytrack aytrack added type/bug The issue is confirmed as a bug. sig/planner SIG: Planner severity/major labels Aug 1, 2023
@ti-chi-bot ti-chi-bot bot added may-affects-5.2 This bug maybe affects 5.2.x versions. may-affects-5.3 This bug maybe affects 5.3.x versions. may-affects-5.4 This bug maybe affects 5.4.x versions. may-affects-6.1 may-affects-6.5 may-affects-7.1 labels Aug 1, 2023
@aytrack
Copy link
Contributor Author

aytrack commented Aug 1, 2023

introduced by #45617

@aytrack aytrack removed may-affects-5.2 This bug maybe affects 5.2.x versions. may-affects-5.3 This bug maybe affects 5.3.x versions. may-affects-5.4 This bug maybe affects 5.4.x versions. may-affects-6.1 may-affects-6.5 may-affects-7.1 labels Aug 1, 2023
@aytrack
Copy link
Contributor Author

aytrack commented Aug 3, 2023

before pr 45617, the plan is

[18:07:05]TiDB root:test>  explain select /*+ inl_join(t2) */ * from t1 join t2 on t1.a = t2.a;
+-------------------------+----------+-----------+----------------------+-----------------------------------------------------------------------------------------------------------------+
| id                      | estRows  | task      | access object        | operator info                                                                                                   |
+-------------------------+----------+-----------+----------------------+-----------------------------------------------------------------------------------------------------------------+
| IndexJoin_12            | 12487.50 | root      |                      | inner join, inner:IndexReader_11, outer key:test.t1.a, inner key:test.t2.a, equal cond:eq(test.t1.a, test.t2.a) |
| ├─IndexReader_21(Build) | 9990.00  | root      |                      | index:IndexFullScan_20                                                                                          |
| │ └─IndexFullScan_20    | 9990.00  | cop[tikv] | table:t1, index:a(a) | keep order:false, stats:pseudo                                                                                  |
| └─IndexReader_11(Probe) | 12487.50 | root      |                      | index:Selection_10                                                                                              |
|   └─Selection_10        | 12487.50 | cop[tikv] |                      | not(isnull(test.t2.a))                                                                                          |
|     └─IndexRangeScan_9  | 12500.00 | cop[tikv] | table:t2, index:a(a) | range: decided by [eq(test.t2.a, test.t1.a)], keep order:false, stats:pseudo                                    |
+-------------------------+----------+-----------+----------------------+-----------------------------------------------------------------------------------------------------------------+
6 rows in set

after

+-------------------------+----------+-----------+----------------------+-----------------------------------------------------------------------------------------------------------------+
| id                      | estRows  | task      | access object        | operator info                                                                                                   |
+-------------------------+----------+-----------+----------------------+-----------------------------------------------------------------------------------------------------------------+
| IndexJoin_12            | 12487.50 | root      |                      | inner join, inner:IndexReader_11, outer key:test.t1.a, inner key:test.t2.a, equal cond:eq(test.t1.a, test.t2.a) |
| ├─IndexReader_32(Build) | 9990.00  | root      |                      | index:IndexFullScan_31                                                                                          |
| │ └─IndexFullScan_31    | 9990.00  | cop[tikv] | table:t1, index:a(a) | keep order:false, stats:pseudo                                                                                  |
| └─IndexReader_11(Probe) | 12487.50 | root      |                      | index:Selection_10                                                                                              |
|   └─Selection_10        | 12487.50 | cop[tikv] |                      | not(isnull(test.t2.a))                                                                                          |
|     └─IndexRangeScan_9  | 12500.00 | cop[tikv] | table:t2, index:a(a) | range: decided by [eq(test.t2.a, test.t1.a)], keep order:false, stats:pseudo                                    |
+-------------------------+----------+-----------+----------------------+-----------------------------------------------------------------------------------------------------------------+
6 rows in set

@qw4990
Copy link
Contributor

qw4990 commented Aug 4, 2023

These 2 plans are the same, just have some different operator IDs. Please help take a look at this issue @wshwsh12

@qw4990 qw4990 added sig/execution SIG execution and removed sig/planner SIG: Planner labels Aug 8, 2023
@wshwsh12 wshwsh12 added affects-6.5 This bug affects the 6.5.x(LTS) versions. affects-7.1 This bug affects the 7.1.x(LTS) versions. affects-5.4 This bug affects the 5.4.x(LTS) versions. affects-6.1 This bug affects the 6.1.x(LTS) versions. labels Aug 8, 2023
@wshwsh12 wshwsh12 assigned wshwsh12 and unassigned qw4990 Aug 8, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
affects-5.4 This bug affects the 5.4.x(LTS) versions. affects-6.1 This bug affects the 6.1.x(LTS) versions. affects-6.5 This bug affects the 6.5.x(LTS) versions. affects-7.1 This bug affects the 7.1.x(LTS) versions. severity/major sig/execution SIG execution type/bug The issue is confirmed as a bug.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants