Bug #116400 Contribution by Tencent: crash on explain format=tree for conn with subquery
Submitted: 18 Oct 2024 4:06 Modified: 18 Oct 2024 5:56
Reporter: Peiyuan Liu Email Updates:
Status: Verified Impact on me:
None 
Category:MySQL Server: Optimizer Severity:S2 (Serious)
Version:trunk (9.1.0), 8.0.30, 8.4.3, 8.4.0 OS:Any
Assigned to: CPU Architecture:Any

[18 Oct 2024 4:06] Peiyuan Liu
Description:
Suppose query_connection is executing a SQL with subquery, and stops at sync point BEFORE_RESET_QUERY_PLAN.

Then we explain it in another explain_connection:
```
explain format=tree for connection <query_connection id>;
```

mysqld will crash: Assertion `current_thd->lex->using_hypergraph_optimizer()` failed.

Tested version: 8.0.30, trunk (9.1.0, hash: 61a3a1d8ef15512396b4c2af46e922a19bf2b174)

How to repeat:
## new mtr test case: explain_other_crash.test
```
--echo # Bug# CRASH IN SYNC_POINT BEFORE_RESET_QUERY_PLAN DURING EXPLAIN FOR CONNECTION

# JSON format is different in hypergraph. And TRADITIONAL format does not work
# with hypergraph.
--source include/not_hypergraph.inc

#
# We need the Debug Sync Facility.
#
--source include/have_debug.inc
--source include/have_debug_sync.inc

CREATE DATABASE mysqltest1;
USE mysqltest1;
DROP TABLE IF EXISTS t1;
CREATE TABLE t1(
  ID int(10) unsigned NOT NULL auto_increment,
  Member_ID varchar(15) NOT NULL default '',
  Action varchar(12) NOT NULL,
  Action_Date datetime NOT NULL,
  Track varchar(15) default NULL,
  User varchar(12) default NULL,
  Date_Updated timestamp NOT NULL default CURRENT_TIMESTAMP on update
    CURRENT_TIMESTAMP,
  PRIMARY KEY (ID),
  KEY Action (Action),
  KEY Action_Date (Action_Date)
);

INSERT INTO t1(Member_ID, Action, Action_Date, Track) VALUES
  ('111111', 'Disenrolled', '2006-03-01', 'CAD' ),
  ('111111', 'Enrolled', '2006-03-01', 'CAD' ),
  ('111111', 'Disenrolled', '2006-07-03', 'CAD' ),
  ('222222', 'Enrolled', '2006-03-07', 'CAD' ),
  ('222222', 'Enrolled', '2006-03-07', 'CHF' ),
  ('222222', 'Disenrolled', '2006-08-02', 'CHF' ),
  ('333333', 'Enrolled', '2006-03-01', 'CAD' ),
  ('333333', 'Disenrolled', '2006-03-01', 'CAD' ),
  ('444444', 'Enrolled', '2006-03-01', 'CAD' ),
  ('555555', 'Disenrolled', '2006-03-01', 'CAD' ),
  ('555555', 'Enrolled', '2006-07-21', 'CAD' ),
  ('555555', 'Disenrolled', '2006-03-01', 'CHF' ),
  ('666666', 'Enrolled', '2006-02-09', 'CAD' ),
  ('666666', 'Enrolled', '2006-05-12', 'CHF' ),
  ('666666', 'Disenrolled', '2006-06-01', 'CAD' );

connect (ce, localhost, root,, mysqltest1);
connect (cq, localhost, root,, mysqltest1);

connection cq;
use mysqltest1;

--echo #
--echo # Bug# CRASH IN SYNC_POINT BEFORE_RESET_QUERY_PLAN DURING EXPLAIN FOR CONNECTION
--echo #

let $point= before_reset_query_plan;
let $query= SELECT GROUP_CONCAT(Track SEPARATOR ', ') FROM t1 WHERE Member_ID=111111 AND Action='Enrolled' AND (Track,Action_Date) IN (SELECT Track, MAX(Action_Date) FROM t1 WHERE Member_ID=111111 GROUP BY Track HAVING Track>='CAD' AND MAX(Action_Date)>'2006-03-01');

connection cq;
let $QID= `SELECT CONNECTION_ID()`;
eval SET DEBUG_SYNC= '$point SIGNAL ready_for_explain WAIT_FOR explained';
send_eval $query;

connection ce;

let $fmt= FORMAT=TREE;
--echo EXPLAIN $fmt FOR QUERY '$query'
# Let the query being explained reach the sync point
SET DEBUG_SYNC= 'now WAIT_FOR ready_for_explain';
SET DEBUG_SYNC= 'after_explain_other SIGNAL explained';
--eval EXPLAIN $fmt FOR CONNECTION $QID;

DROP DATABASE mysqltest1;
--echo # End of test

disconnect cq;
disconnect ce;

```

## mtr result: CRASH
```
Logging: /data/workspace/mysql-server/mysql-test/mysql-test-run.pl  explain_other_crash.test
MySQL Version 9.1.0
Checking supported features
 - Binaries are debug compiled
Using 'all' suites
Collecting tests
Checking leftover processes
Removing old var directory
Creating var directory '/data/workspace/mysql-server/build/mysql-test/var'
Installing system database
Using parallel: 1

==============================================================================
                  TEST NAME                       RESULT  TIME (ms) COMMENT
------------------------------------------------------------------------------
[ 50%] main.explain_other_crash                  [ fail ]
        Test ended at 2024-10-18 11:21:47

CURRENT_TEST: main.explain_other_crash
mysqltest: At line 72: Query 'EXPLAIN $fmt FOR CONNECTION $QID;' failed.
ERROR 2013 (HY000): Lost connection to MySQL server during query
safe_process[650870]: Child process: 650871, exit: 1

Server [mysqld.1 - pid: 650768, winpid: 650768, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
2024-10-18T03:21:38.731130Z 0 [Note] [MY-013667] [Server] Error-log destination "stderr" is not a file. Can not restore error log messages from previous run.
2024-10-18T03:21:38.504654Z 0 [System] [MY-015015] [Server] MySQL Server - start.
2024-10-18T03:21:38.720823Z 0 [Warning] [MY-013711] [Server] Manifest file '/data/workspace/mysql-server/build/runtime_output_directory/mysqld.my' is not read-only. For better security, please make sure that the file is read-only.
2024-10-18T03:21:38.723912Z 0 [Warning] [MY-010099] [Server] Insecure configuration for --secure-file-priv: Data directory is accessible through --secure-file-priv. Consider choosing a different directory.
2024-10-18T03:21:38.723934Z 0 [Warning] [MY-010101] [Server] Insecure configuration for --secure-file-priv: Location is accessible to all OS users. Consider choosing a different directory.
2024-10-18T03:21:38.724070Z 0 [Note] [MY-013932] [Server] BuildID[sha1]=46379f9bdc0662cd5a15274749574fd1e81125f0
2024-10-18T03:21:38.724092Z 0 [Note] [MY-010949] [Server] Basedir set to /data/workspace/mysql-server/build/.
2024-10-18T03:21:38.724113Z 0 [System] [MY-010116] [Server] /data/workspace/mysql-server/build/runtime_output_directory/mysqld (mysqld 9.1.0-debug) starting as process 650769
2024-10-18T03:21:38.733014Z 0 [Warning] [MY-010075] [Server] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: 1669df4f-8d00-11ef-938c-2a3db9cf0f38.
2024-10-18T03:21:38.737857Z 0 [Note] [MY-015140] [InnoDB] Using innodb_flush_method=O_DIRECT
2024-10-18T03:21:38.738589Z 0 [Note] [MY-010747] [Server] Plugin 'FEDERATED' is disabled.
2024-10-18T03:21:38.738726Z 0 [Note] [MY-010747] [Server] Plugin 'ndbcluster' is disabled.
2024-10-18T03:21:38.738862Z 0 [Note] [MY-010747] [Server] Plugin 'ndbinfo' is disabled.
2024-10-18T03:21:38.738895Z 0 [Note] [MY-010747] [Server] Plugin 'ndb_transid_mysql_connection_map' is disabled.
2024-10-18T03:21:38.742391Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2024-10-18T03:21:38.742438Z 1 [Note] [MY-013546] [InnoDB] Atomic write enabled
2024-10-18T03:21:38.742465Z 1 [Note] [MY-012932] [InnoDB] PUNCH HOLE support available
2024-10-18T03:21:38.742486Z 1 [Note] [MY-012937] [InnoDB] !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2024-10-18T03:21:38.742494Z 1 [Note] [MY-012944] [InnoDB] Uses event mutexes
2024-10-18T03:21:38.742516Z 1 [Note] [MY-012945] [InnoDB] GCC builtin __atomic_thread_fence() is used for memory barrier
2024-10-18T03:21:38.742526Z 1 [Note] [MY-012948] [InnoDB] Compressed tables use zlib 1.3.1
2024-10-18T03:21:38.747813Z 1 [Note] [MY-012951] [InnoDB] Using hardware accelerated crc32 and polynomial multiplication.
2024-10-18T03:21:38.748365Z 1 [Note] [MY-012203] [InnoDB] Directories to scan './'
2024-10-18T03:21:38.748424Z 1 [Note] [MY-012204] [InnoDB] Scanning './'
2024-10-18T03:21:38.749382Z 1 [Note] [MY-012208] [InnoDB] Completed space ID check of 8 files.
2024-10-18T03:21:38.750388Z 1 [Note] [MY-012955] [InnoDB] Initializing buffer pool, total size = 24.000000M, instances = 1, chunk size =24.000000M 
2024-10-18T03:21:38.841883Z 1 [Note] [MY-012957] [InnoDB] Completed initialization of buffer pool
2024-10-18T03:21:38.848457Z 0 [Note] [MY-011952] [InnoDB] If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2024-10-18T03:21:38.849745Z 1 [Note] [MY-013532] [InnoDB] Using './#ib_16384_0.dblwr' for doublewrite
2024-10-18T03:21:38.863468Z 1 [Note] [MY-013532] [InnoDB] Using './#ib_16384_1.dblwr' for doublewrite
2024-10-18T03:21:38.934623Z 1 [Note] [MY-013566] [InnoDB] Double write buffer files: 2
2024-10-18T03:21:38.934670Z 1 [Note] [MY-013565] [InnoDB] Double write buffer pages per instance: 128
2024-10-18T03:21:38.934705Z 1 [Note] [MY-013532] [InnoDB] Using './#ib_16384_0.dblwr' for doublewrite
2024-10-18T03:21:38.934724Z 1 [Note] [MY-013532] [InnoDB] Using './#ib_16384_1.dblwr' for doublewrite
2024-10-18T03:21:39.354801Z 1 [Note] [MY-013883] [InnoDB] The latest found checkpoint is at lsn = 20150969 in redo log file ./#innodb_redo/#ib_redo61.
2024-10-18T03:21:39.354912Z 1 [Note] [MY-013086] [InnoDB] Starting to parse redo log at lsn = 20150846, whereas checkpoint_lsn = 20150969 and start_lsn = 20150784
2024-10-18T03:21:39.388925Z 1 [Note] [MY-013083] [InnoDB] Log background threads are being started...
2024-10-18T03:21:39.392384Z 1 [Note] [MY-012532] [InnoDB] Applying a batch of 0 redo log records ...
2024-10-18T03:21:39.392434Z 1 [Note] [MY-012535] [InnoDB] Apply batch completed!
2024-10-18T03:21:39.403002Z 1 [Note] [MY-013252] [InnoDB] Using undo tablespace './undo_001'.
2024-10-18T03:21:39.404157Z 1 [Note] [MY-013252] [InnoDB] Using undo tablespace './undo_002'.
2024-10-18T03:21:39.415613Z 1 [Note] [MY-012910] [InnoDB] Opened 2 existing undo tablespaces.
2024-10-18T03:21:39.415797Z 1 [Note] [MY-011980] [InnoDB] GTID recovery trx_no: 1079
2024-10-18T03:21:39.554674Z 1 [Note] [MY-013776] [InnoDB] Parallel initialization of rseg complete
2024-10-18T03:21:39.554758Z 1 [Note] [MY-013777] [InnoDB] Time taken to initialize rseg using 4 thread: 139 ms.
2024-10-18T03:21:39.555061Z 1 [Note] [MY-012923] [InnoDB] Creating shared tablespace for temporary tables
2024-10-18T03:21:39.555651Z 1 [Note] [MY-012265] [InnoDB] Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2024-10-18T03:21:39.588647Z 1 [Note] [MY-012266] [InnoDB] File './ibtmp1' size is now 12 MB.
2024-10-18T03:21:39.589071Z 1 [Note] [MY-013627] [InnoDB] Scanning temp tablespace dir:'./#innodb_temp/'
2024-10-18T03:21:39.655821Z 1 [Note] [MY-013018] [InnoDB] Created 128 and tracked 128 new rollback segment(s) in the temporary tablespace. 128 are now active.
2024-10-18T03:21:39.656921Z 1 [Note] [MY-012976] [InnoDB] 9.1.0 started; log sequence number 20150979
2024-10-18T03:21:39.657811Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2024-10-18T03:21:39.701415Z 1 [Note] [MY-011089] [Server] Data dictionary restarting version '90000'.
2024-10-18T03:21:40.767943Z 1 [Note] [MY-012357] [InnoDB] Reading DD tablespace files
2024-10-18T03:21:40.777750Z 1 [Note] [MY-012356] [InnoDB] Scanned 10 tablespaces. Validated 10.
2024-10-18T03:21:41.012986Z 1 [Note] [MY-010006] [Server] Using data dictionary with version '90000'.
2024-10-18T03:21:41.053805Z 0 [Note] [MY-011245] [Server] Plugin mysqlx reported: 'Scheduler 'work', set number of threads to 2'
2024-10-18T03:21:41.053877Z 0 [Note] [MY-011245] [Server] Plugin mysqlx reported: 'Scheduler 'work', create threads'
2024-10-18T03:21:41.053935Z 0 [Note] [MY-011245] [Server] Plugin mysqlx reported: 'Scheduler 'work', create threads'
2024-10-18T03:21:41.053967Z 0 [Note] [MY-011245] [Server] Plugin mysqlx reported: 'Scheduler "work" started.'
2024-10-18T03:21:41.053975Z 0 [Note] [MY-011245] [Server] Plugin mysqlx reported: 'Scheduler 'network', create threads'
2024-10-18T03:21:41.054015Z 0 [Note] [MY-011245] [Server] Plugin mysqlx reported: 'Scheduler "network" started.'
2024-10-18T03:21:41.054078Z 0 [Note] [MY-011245] [Server] Plugin mysqlx reported: 'TCP Sockets address is '*' and port is 13020'
2024-10-18T03:21:41.054158Z 0 [Note] [MY-011332] [Server] Plugin mysqlx reported: 'IPv6 is available'
2024-10-18T03:21:41.054228Z 0 [Note] [MY-011245] [Server] Plugin mysqlx reported: 'UNIX Socket is /data/workspace/mysql-server/build/mysql-test/var/tmp/mysqlx.1.sock'
2024-10-18T03:21:41.055093Z 0 [Note] [MY-011323] [Server] Plugin mysqlx reported: 'X Plugin ready for connections. bind-address: '::' port: 13020'
2024-10-18T03:21:41.055121Z 0 [Note] [MY-011323] [Server] Plugin mysqlx reported: 'X Plugin ready for connections. socket: '/data/workspace/mysql-server/build/mysql-test/var/tmp/mysqlx.1.sock''
2024-10-18T03:21:42.386010Z 0 [Note] [MY-010902] [Server] Thread priority attribute setting in Resource Group SQL shall be ignored due to unsupported platform or insufficient privilege.
2024-10-18T03:21:42.414422Z 0 [Note] [MY-013911] [Server] Crash recovery finished in binlog engine. No attempts to commit, rollback or prepare any transactions.
2024-10-18T03:21:42.414498Z 0 [Note] [MY-013911] [Server] Crash recovery finished in InnoDB engine. No attempts to commit, rollback or prepare any transactions.
2024-10-18T03:21:42.426462Z 0 [Note] [MY-012487] [InnoDB] DDL log recovery : begin
2024-10-18T03:21:42.427210Z 0 [Note] [MY-012488] [InnoDB] DDL log recovery : end
2024-10-18T03:21:42.427913Z 0 [Note] [MY-011946] [InnoDB] Loading buffer pool(s) from /data/workspace/mysql-server/build/mysql-test/var/mysqld.1/data/ib_buffer_pool
2024-10-18T03:21:42.475986Z 0 [Note] [MY-011946] [InnoDB] Buffer pool(s) load completed at 241018  6:21:42
2024-10-18T03:21:42.507461Z 0 [Note] [MY-010303] [Server] Skipping generation of SSL certificates as options related to SSL are specified.
2024-10-18T03:21:42.508758Z 0 [Warning] [MY-010068] [Server] CA certificate /data/workspace/mysql-server/mysql-test/std_data/cacert.pem is self signed.
2024-10-18T03:21:42.508812Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel.
2024-10-18T03:21:42.508827Z 0 [Note] [MY-010310] [Server] Skipping generation of RSA key pair as --sha256_password_auto_generate_rsa_keys is set to OFF.
2024-10-18T03:21:42.508839Z 0 [Note] [MY-010310] [Server] Skipping generation of RSA key pair as --caching_sha2_password_auto_generate_rsa_keys is set to OFF.
2024-10-18T03:21:42.509050Z 0 [Note] [MY-010252] [Server] Server hostname (bind-address): '*'; port: 13000
2024-10-18T03:21:42.509094Z 0 [Note] [MY-010253] [Server] IPv6 is available.
2024-10-18T03:21:42.509106Z 0 [Note] [MY-010264] [Server]   - '::' resolves to '::';
2024-10-18T03:21:42.509121Z 0 [Note] [MY-010251] [Server] Server socket created on IP: '::'.
2024-10-18T03:21:42.533200Z 0 [Warning] [MY-000067] [Server] unknown variable 'loose-mysqlx-ssl=DISABLED'.
2024-10-18T03:21:42.734367Z 0 [Note] [MY-011025] [Repl] Failed to start replica threads for channel ''.
2024-10-18T03:21:42.749189Z 5 [Note] [MY-010051] [Server] Event Scheduler: scheduler thread started with id 5
2024-10-18T03:21:42.749615Z 0 [Note] [MY-011240] [Server] Plugin mysqlx reported: 'Using SSL configuration from MySQL Server'
2024-10-18T03:21:42.750087Z 0 [Note] [MY-011243] [Server] Plugin mysqlx reported: 'Using OpenSSL for TLS connections'
2024-10-18T03:21:42.750119Z 0 [Note] [MY-011245] [Server] Plugin mysqlx reported: 'Scheduler 'network', post task'
2024-10-18T03:21:42.750128Z 0 [Note] [MY-011245] [Server] Plugin mysqlx reported: 'Scheduler 'network', create threads'
2024-10-18T03:21:42.750195Z 0 [Note] [MY-011245] [Server] Plugin mysqlx reported: 'Scheduler 'network', post task'
2024-10-18T03:21:42.750203Z 0 [Note] [MY-011245] [Server] Plugin mysqlx reported: 'Scheduler 'network', create threads'
2024-10-18T03:21:42.750276Z 0 [Note] [MY-011245] [Server] Plugin mysqlx reported: 'Socket_acceptors_task::pre_loop'
2024-10-18T03:21:42.750327Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Bind-address: '::' port: 13020, socket: /data/workspace/mysql-server/build/mysql-test/var/tmp/mysqlx.1.sock
2024-10-18T03:21:42.750527Z 0 [System] [MY-010931] [Server] /data/workspace/mysql-server/build/runtime_output_directory/mysqld: ready for connections. Version: '9.1.0-debug'  socket: '/data/workspace/mysql-server/build/mysql-test/var/tmp/mysqld.1.sock'  port: 13000  Source distribution.
mysqld: /data/workspace/mysql-server/sql/item_subselect.cc:588: virtual AccessPath* Item_in_subselect::root_access_path() const: Assertion `current_thd->lex->using_hypergraph_optimizer()' failed.
2024-10-18T03:21:44Z UTC - mysqld got signal 6 ;
Most likely, you have hit a bug, but this error can also be caused by malfunctioning hardware.
BuildID[sha1]=46379f9bdc0662cd5a15274749574fd1e81125f0
Thread pointer: 0x7f9c58001040
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7f9d504f3a50 thread_stack 0x100000
 #0 0x3890058 print_fatal_signal at /data/workspace/mysql-server/sql/signal_handler.cc:319
 #1 0x3890293 _Z19handle_fatal_signaliP9siginfo_tPv at /data/workspace/mysql-server/sql/signal_handler.cc:399
 #2 0x7f9d7269fcef <unknown>
 #3 0x7f9d70b3dacf <unknown>
 #4 0x7f9d70b10ea4 <unknown>
 #5 0x7f9d70b10d78 <unknown>
 #6 0x7f9d70b36425 <unknown>
 #7 0x3b992c7 _ZNK17Item_in_subselect16root_access_pathEv at /data/workspace/mysql-server/sql/item_subselect.cc:588
 #8 0x3c3612a operator() at /data/workspace/mysql-server/sql/join_optimizer/explain_access_path.cc:341
 #9 0x3c447bb operator() at /data/workspace/mysql-server/sql/item.h:3818
 #10 0x3c461b6 walk_helper_thunk<WalkItem<const AddSubqueryPaths(const Item*, char const*, std::vector<ExplainChild>*)::<lambda(const Item*)>&>::<lambda(const Item*)>&> at /data/workspace/mysql-server/sql/item.h:2639
 #11 0x3b9966f _ZN14Item_subselect4walkEM4ItemFbPhE9enum_walkS1_ at /data/workspace/mysql-server/sql/item_subselect.cc:642
 #12 0x3b99c80 _ZN17Item_in_subselect4walkEM4ItemFbPhE9enum_walkS1_ at /data/workspace/mysql-server/sql/item_subselect.cc:759
 #13 0x3b1fb38 _ZN9Item_func4walkEM4ItemFbPhE9enum_walkS1_ at /data/workspace/mysql-server/sql/item_func.cc:637
 #14 0x3accc52 _ZN9Item_cond4walkEM4ItemFbPhE9enum_walkS1_ at /data/workspace/mysql-server/sql/item_cmpfunc.cc:5968
 #15 0x3c46207 WalkItem<WalkItem<const AddSubqueryPaths(const Item*, char const*, std::vector<ExplainChild>*)::<lambda(const Item*)>&>::<lambda(const Item*)>&> at /data/workspace/mysql-server/sql/item.h:3809
 #16 0x3c447ed WalkItem<const AddSubqueryPaths(const Item*, char const*, std::vector<ExplainChild>*)::<lambda(const Item*)>&> at /data/workspace/mysql-server/sql/item.h:3819
 #17 0x3c36500 AddSubqueryPaths at /data/workspace/mysql-server/sql/join_optimizer/explain_access_path.cc:383
 #18 0x3c3dea0 SetObjectMembers at /data/workspace/mysql-server/sql/join_optimizer/explain_access_path.cc:1610
 #19 0x3c41e98 ExplainAccessPath at /data/workspace/mysql-server/sql/join_optimizer/explain_access_path.cc:2032
 #20 0x3c38be0 AddChildrenToObject at /data/workspace/mysql-server/sql/join_optimizer/explain_access_path.cc:843
 #21 0x3c4219c ExplainAccessPath at /data/workspace/mysql-server/sql/join_optimizer/explain_access_path.cc:2080
 #22 0x3c38e8e ExplainQueryPlan at /data/workspace/mysql-server/sql/join_optimizer/explain_access_path.cc:866
 #23 0x3c42521 _Z14PrintQueryPlanB5cxx11P3THDPKS_P16Query_expression at /data/workspace/mysql-server/sql/join_optimizer/explain_access_path.cc:2130
 #24 0x3cda48f ExplainIterator at /data/workspace/mysql-server/sql/opt_explain.cc:2127
 #25 0x3cdaaaa _Z13explain_queryP3THDPKS_P16Query_expression at /data/workspace/mysql-server/sql/opt_explain.cc:2286
 #26 0x3cdb773 _ZN28Sql_cmd_explain_other_thread7executeEP3THD at /data/workspace/mysql-server/sql/opt_explain.cc:2534
 #27 0x3650466 _Z21mysql_execute_commandP3THDb at /data/workspace/mysql-server/sql/sql_parse.cc:4669
 #28 0x3652710 _Z20dispatch_sql_commandP3THDP12Parser_stateb at /data/workspace/mysql-server/sql/sql_parse.cc:5331
 #29 0x3648db1 _Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command at /data/workspace/mysql-server/sql/sql_parse.cc:2122
 #30 0x3646dc3 _Z10do_commandP3THD at /data/workspace/mysql-server/sql/sql_parse.cc:1466
 #31 0x3878f60 handle_connection at /data/workspace/mysql-server/sql/conn_handler/connection_handler_per_thread.cc:304
 #32 0x58f952d pfs_spawn_thread at /data/workspace/mysql-server/storage/perfschema/pfs.cc:3067
 #33 0x7f9d726951c9 <unknown>
 #34 0x7f9d70b28e72 <unknown>
 #35 0xffffffffffffffff <unknown>

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f9c5800bb60): EXPLAIN FORMAT=TREE FOR CONNECTION 11
Connection ID (thread ID): 10
Status: NOT_KILLED

The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
Writing a core file
safe_process[650768]: Child process: 650769, killed by signal: 6
----------SERVER LOG END-------------

Mysqltest client output from logfile
----------- MYSQLTEST OUTPUT START -----------

# Bug# CRASH IN SYNC_POINT BEFORE_RESET_QUERY_PLAN DURING EXPLAIN FOR CONNECTION
CREATE DATABASE mysqltest1;
USE mysqltest1;
DROP TABLE IF EXISTS t1;
Warnings:
Note	1051	Unknown table 'mysqltest1.t1'
CREATE TABLE t1(
ID int(10) unsigned NOT NULL auto_increment,
Member_ID varchar(15) NOT NULL default '',
Action varchar(12) NOT NULL,
Action_Date datetime NOT NULL,
Track varchar(15) default NULL,
User varchar(12) default NULL,
Date_Updated timestamp NOT NULL default CURRENT_TIMESTAMP on update
CURRENT_TIMESTAMP,
PRIMARY KEY (ID),
KEY Action (Action),
KEY Action_Date (Action_Date)
);
Warnings:
Warning	1681	Integer display width is deprecated and will be removed in a future release.
INSERT INTO t1(Member_ID, Action, Action_Date, Track) VALUES
('111111', 'Disenrolled', '2006-03-01', 'CAD' ),
('111111', 'Enrolled', '2006-03-01', 'CAD' ),
('111111', 'Disenrolled', '2006-07-03', 'CAD' ),
('222222', 'Enrolled', '2006-03-07', 'CAD' ),
('222222', 'Enrolled', '2006-03-07', 'CHF' ),
('222222', 'Disenrolled', '2006-08-02', 'CHF' ),
('333333', 'Enrolled', '2006-03-01', 'CAD' ),
('333333', 'Disenrolled', '2006-03-01', 'CAD' ),
('444444', 'Enrolled', '2006-03-01', 'CAD' ),
('555555', 'Disenrolled', '2006-03-01', 'CAD' ),
('555555', 'Enrolled', '2006-07-21', 'CAD' ),
('555555', 'Disenrolled', '2006-03-01', 'CHF' ),
('666666', 'Enrolled', '2006-02-09', 'CAD' ),
('666666', 'Enrolled', '2006-05-12', 'CHF' ),
('666666', 'Disenrolled', '2006-06-01', 'CAD' );
use mysqltest1;
#
# Bug# CRASH IN SYNC_POINT BEFORE_RESET_QUERY_PLAN DURING EXPLAIN FOR CONNECTION
#
SET DEBUG_SYNC= 'before_reset_query_plan SIGNAL ready_for_explain WAIT_FOR explained';
SELECT GROUP_CONCAT(Track SEPARATOR ', ') FROM t1 WHERE Member_ID=111111 AND Action='Enrolled' AND (Track,Action_Date) IN (SELECT Track, MAX(Action_Date) FROM t1 WHERE Member_ID=111111 GROUP BY Track HAVING Track>='CAD' AND MAX(Action_Date)>'2006-03-01');
EXPLAIN FORMAT=TREE FOR QUERY 'SELECT GROUP_CONCAT(Track SEPARATOR ', ') FROM t1 WHERE Member_ID=111111 AND Action='Enrolled' AND (Track,Action_Date) IN (SELECT Track, MAX(Action_Date) FROM t1 WHERE Member_ID=111111 GROUP BY Track HAVING Track>='CAD' AND MAX(Action_Date)>'2006-03-01')'
SET DEBUG_SYNC= 'now WAIT_FOR ready_for_explain';
SET DEBUG_SYNC= 'after_explain_other SIGNAL explained';
EXPLAIN FORMAT=TREE FOR CONNECTION 11;;

------------ MYSQLTEST OUTPUT END -----------

 - the logfile can be found in '/data/workspace/mysql-server/build/mysql-test/var/log/main.explain_other_crash/explain_other_crash.log'

 - found 'core.650769' (0/5)

Trying 'dbx' to get a backtrace

Trying 'gdb' to get a backtrace
Core generated by '/data/workspace/mysql-server/build/runtime_output_directory/mysqld'
Output from gdb follows. The first stack trace is from the failing thread.
The following stack traces are from all threads (so the failing one is
duplicated).
-----------------
<backtrace ignored ...>

[100%] shutdown_report                           [ pass ]       
------------------------------------------------------------------------------
The servers were restarted 0 times
The servers were reinitialized 0 times
Spent 0.000 of 100 seconds executing testcases

Completed: Failed 1/2 tests, 50.00% were successful.

Failing test(s): main.explain_other_crash

The log files in var/log may give you some hint of what went wrong.

If you want to report this error, please read first the documentation
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html

mysql-test-run: *** ERROR: there were failing test cases

```
[18 Oct 2024 4:34] MySQL Verification Team
Hello Peiyuan Liu,

Thank you for the report and test case.
Verified as described.

regards,
Umesh
[18 Oct 2024 5:56] Peiyuan Liu
In fact, it's not a bug that occurs only in debug builds.

In release-builds, `explain format=tree for conn` at sync point BEFORE_RESET_QUERY_PLAN gives incorrect query plan.

Take the same query in the test case as an example, the correct plan (from explain <query>) is:
```
-> Aggregate: group_concat(t1.Track separator ', ')  (cost=0.764 rows=1)
    -> Filter: ((t1.Member_ID = 111111) and <in_optimizer>((t1.Track,t1.Action_Date),(t1.Track,t1.Action_Date) in (select #2)))  (cost=0.58 rows=0.8)
        -> Index lookup on t1 using Action (Action = 'Enrolled')  (cost=0.58 rows=8)
        -> Select #2 (subquery in condition; run only once)
            -> Filter: ((t1.Track = `<materialized_subquery>`.Track) and (t1.Action_Date = `<materialized_subquery>`.`MAX(Action_Date)`))  (cost=0..0 rows=0)
                -> Limit: 1 row(s)  (cost=0..0 rows=0)
                    -> Index lookup on <materialized_subquery> using <auto_distinct_key> (Track = t1.Track, MAX(Action_Date) = t1.Action_Date)
                        -> Materialize with deduplication  (cost=0..0 rows=0)
                            -> Filter: ((t1.Track >= 'CAD') and (max(t1.Action_Date) > '2006-03-01'))
                                -> Table scan on <temporary>
                                    -> Aggregate using temporary table
                                        -> Filter: (t1.Member_ID = 111111)  (cost=1.75 rows=1.5)
                                            -> Table scan on t1  (cost=1.75 rows=15)
```

Although we can't use debug sync utils for testing in release builds, we can mimic the behavior of release builds in debug builds.
Just comment the following line of code in `Item_in_subselect::root_access_path()`:
```
assert(current_thd->lex->using_hypergraph_optimizer());
```

Then, in debug-builds, run the same mtr case as before. mysqld gives an incorrect plan as follows:
```
-> Aggregate: group_concat(t1.Track separator ', ')  (cost=3.14 rows=1)
    -> Filter: ((t1.Member_ID = 111111) and <in_optimizer>((t1.Track,t1.Action_Date),<exists>(select #2)))  (cost=1.3 rows=8)
        -> Index lookup on t1 using Action (Action = 'Enrolled')  (cost=1.3 rows=8)
        -> Select #2 (subquery in condition; dependent)
            -> <not executable by iterator executor>
```