[MDEV-23451] Server crash with ORDER BY & GROUP BY Created: 2020-08-11  Updated: 2020-10-19  Resolved: 2020-10-19

Status: Closed
Project: MariaDB Server
Component/s: Optimizer
Affects Version/s: 10.3.24
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Pavel Znamensky Assignee: Unassigned
Resolution: Incomplete Votes: 0
Labels: need_feedback


 Description   

We've got several quite big tables and when we're trying to execute the following SQL, MariaDB Server crashes:

SELECT b.id book_id,
       ntr.id topic_id,
       ntr.type
FROM books b
INNER JOIN
  (SELECT nt.id,
          ntr.topicable_id,
          CASE
              WHEN nt.parent_id IS NULL THEN 'topic'
              ELSE 'subtopic'
          END AS TYPE
   FROM new_topic_resources ntr
   JOIN new_topics nt ON nt.id = ntr.topic_id
   ORDER BY RAND()) ntr ON b.id = ntr.topicable_id
GROUP BY book_id

16:53:22 srv systemd[1]: Starting MariaDB 10.3.24 database server...
16:53:22 srv mysqld[30370]: 2020-08-11 16:53:22 0 [Note] /usr/sbin/mysqld (mysqld 10.3.24-MariaDB-log) starting as process 30370 ...
16:53:22 srv mysqld[30370]: 2020-08-11 16:53:22 0 [Warning] Could not increase number of max_open_files to more than 16384 (request: 66383)
16:53:22 srv mysqld[30370]: 2020-08-11 16:53:22 0 [ERROR] mysqld: Plugin 'server_audit' already installed
16:53:22 srv mysqld[30370]: 2020-08-11 16:53:22 0 [Note] InnoDB: Using Linux native AIO
16:53:22 srv mysqld[30370]: 2020-08-11 16:53:22 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
16:53:22 srv mysqld[30370]: 2020-08-11 16:53:22 0 [Note] InnoDB: Uses event mutexes
16:53:22 srv mysqld[30370]: 2020-08-11 16:53:22 0 [Note] InnoDB: Compressed tables use zlib 1.2.7
16:53:22 srv mysqld[30370]: 2020-08-11 16:53:22 0 [Note] InnoDB: Number of pools: 1
16:53:22 srv mysqld[30370]: 2020-08-11 16:53:22 0 [Note] InnoDB: Using SSE2 crc32 instructions
16:53:22 srv mysqld[30370]: 2020-08-11 16:53:22 0 [Note] InnoDB: Initializing buffer pool, total size = 15G, instances = 8, chunk size = 128M
16:53:23 srv mysqld[30370]: 2020-08-11 16:53:23 0 [Note] InnoDB: Completed initialization of buffer pool
16:53:23 srv mysqld[30370]: 2020-08-11 16:53:23 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
16:53:23 srv mysqld[30370]: 2020-08-11 16:53:23 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=24589337929377
16:53:23 srv mysqld[30370]: 2020-08-11 16:53:23 0 [Note] InnoDB: Last binlog file './mysql-bin.006661', position 562225814
16:53:24 srv mysqld[30370]: 2020-08-11 16:53:24 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
16:53:24 srv mysqld[30370]: 2020-08-11 16:53:24 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
16:53:24 srv mysqld[30370]: 2020-08-11 16:53:24 0 [Note] InnoDB: Creating shared tablespace for temporary tables
16:53:24 srv mysqld[30370]: 2020-08-11 16:53:24 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
16:53:24 srv mysqld[30370]: 2020-08-11 16:53:24 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
16:53:24 srv mysqld[30370]: 2020-08-11 16:53:24 0 [Note] InnoDB: 10.3.24 started; log sequence number 24589337929386; transaction id 107442739966
16:53:24 srv mysqld[30370]: 2020-08-11 16:53:24 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
16:53:24 srv mysqld[30370]: 2020-08-11 16:53:24 0 [Note] Plugin 'FEEDBACK' is disabled.
16:53:24 srv mysqld[30370]: 200811 16:53:24 server_audit: server_audit_excl_users set to 'haproxy_check,pmm'.
16:53:24 srv mysqld[30370]: 200811 16:53:24 server_audit: MariaDB Audit Plugin version 1.4.8 STARTED.
16:53:24 srv mysqld[30370]: 200811 16:53:24 server_audit: logging started to the file server_audit.log.
16:53:24 srv mysqld[30370]: 2020-08-11 16:53:24 0 [Note] Recovering after a crash using mysql-bin
16:53:24 srv mysqld[30370]: 2020-08-11 16:53:24 0 [Note] Starting crash recovery...
16:53:24 srv mysqld[30370]: 2020-08-11 16:53:24 0 [Note] Crash recovery finished.
16:53:24 srv mysqld[30370]: 2020-08-11 16:53:24 0 [Note] Server socket created on IP: '::'.
16:53:24 srv mysqld[30370]: 2020-08-11 16:53:24 0 [Note] Reading of all Master_info entries succeeded
16:53:24 srv mysqld[30370]: 2020-08-11 16:53:24 0 [Note] Added new Master_info '' to hash table
16:53:24 srv mysqld[30370]: 2020-08-11 16:53:24 0 [Note] /usr/sbin/mysqld: ready for connections.
16:53:24 srv mysqld[30370]: Version: '10.3.24-MariaDB-log'  socket: '/var/lib/mysql/mysql.sock'  port: 3306  MariaDB Server
16:53:24 srv systemd[1]: Started MariaDB 10.3.24 database server.
16:53:28 srv mysqld[30370]: 2020-08-11 16:53:28 0 [Note] InnoDB: Buffer pool(s) load completed at 200811 16:53:28
16:55:57 srv mysqld[30370]: 200811 16:55:57 [ERROR] mysqld got signal 11 ;
16:55:57 srv mysqld[30370]: This could be because you hit a bug. It is also possible that this binary
16:55:57 srv mysqld[30370]: or one of the libraries it was linked against is corrupt, improperly built,
16:55:57 srv mysqld[30370]: or misconfigured. This error can also be caused by malfunctioning hardware.
16:55:57 srv mysqld[30370]: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
16:55:57 srv mysqld[30370]: We will try our best to scrape up some info that will hopefully help
16:55:57 srv mysqld[30370]: diagnose the problem, but since we have already crashed,
16:55:57 srv mysqld[30370]: something is definitely wrong and this may fail.
16:55:57 srv mysqld[30370]: Server version: 10.3.24-MariaDB-log
16:55:57 srv mysqld[30370]: key_buffer_size=134217728
16:55:57 srv mysqld[30370]: read_buffer_size=2097152
16:55:57 srv mysqld[30370]: max_used_connections=1
16:55:57 srv mysqld[30370]: max_threads=802
16:55:57 srv mysqld[30370]: thread_count=8
16:55:57 srv mysqld[30370]: It is possible that mysqld could use up to
16:55:57 srv mysqld[30370]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 8361599 K  bytes of memory
16:55:57 srv mysqld[30370]: Hope that's ok; if not, decrease some variables in the equation.
16:55:57 srv mysqld[30370]: Thread pointer: 0x7f7a180009a8
16:55:57 srv mysqld[30370]: Attempting backtrace. You can use the following information to find out
16:55:57 srv mysqld[30370]: where mysqld died. If you see no messages after this, something went
16:55:57 srv mysqld[30370]: terribly wrong...
16:55:57 srv mysqld[30370]: stack_bottom = 0x7f7e841c2d30 thread_stack 0x49000
16:55:57 srv mysqld[30370]: /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0x55e0ba94851e]
16:55:57 srv mysqld[30370]: /usr/sbin/mysqld(handle_fatal_signal+0x30f)[0x55e0ba3dda4f]
16:55:57 srv mysqld[30370]: sigaction.c:0(__restore_rt)[0x7f7e8e1e3630]
16:55:57 srv mysqld[30370]: /usr/sbin/mysqld(_ZN4JOIN18make_sum_func_listER4ListI4ItemES3_bb+0x52)[0x55e0ba2481e2]
16:55:57 srv mysqld[30370]: /usr/sbin/mysqld(_ZN4JOIN21make_aggr_tables_infoEv+0x624)[0x55e0ba249054]
16:55:57 srv mysqld[30370]: /usr/sbin/mysqld(_ZN4JOIN15optimize_stage2Ev+0x1485)[0x55e0ba251735]
16:55:57 srv mysqld[30370]: /usr/sbin/mysqld(_ZN4JOIN14optimize_innerEv+0xff0)[0x55e0ba253740]
16:55:57 srv mysqld[30370]: /usr/sbin/mysqld(_ZN4JOIN8optimizeEv+0x52)[0x55e0ba255102]
16:55:57 srv mysqld[30370]: /usr/sbin/mysqld(_Z12mysql_selectP3THDP10TABLE_LISTjR4ListI4ItemEPS4_jP8st_orderS9_S7_S9_yP13select_resultP18st_select_lex_unitP13st_select_lex+0x94)[0x55e0ba2551e4]
16:55:57 srv mysqld[30370]: /usr/sbin/mysqld(_Z13handle_selectP3THDP3LEXP13select_resultm+0x1cc)[0x55e0ba255d7c]
16:55:57 srv mysqld[30370]: /usr/sbin/mysqld(+0x4daf06)[0x55e0ba105f06]
16:55:57 srv mysqld[30370]: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x63ba)[0x55e0ba1fe8ca]
16:55:57 srv mysqld[30370]: /usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_statebb+0x36d)[0x55e0ba20163d]
16:55:57 srv mysqld[30370]: /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcjbb+0xfe1)[0x55e0ba202ed1]
16:55:57 srv mysqld[30370]: /usr/sbin/mysqld(_Z10do_commandP3THD+0x11b)[0x55e0ba20516b]
16:55:57 srv mysqld[30370]: /usr/sbin/mysqld(_Z24do_handle_one_connectionP7CONNECT+0x1d6)[0x55e0ba2dba86]
16:55:57 srv mysqld[30370]: /usr/sbin/mysqld(handle_one_connection+0x3d)[0x55e0ba2dbb9d]
16:55:58 srv mysqld[30370]: pthread_create.c:0(start_thread)[0x7f7e8e1dbea5]
16:55:58 srv mysqld[30370]: /lib64/libc.so.6(clone+0x6d)[0x7f7e8c57c8dd]
16:55:58 srv mysqld[30370]: Trying to get some variables.
16:55:58 srv mysqld[30370]: Some pointers may be invalid and cause the dump to abort.
16:55:58 srv systemd[1]: mariadb.service: main process exited, code=killed, status=11/SEGV

I've tried to unset split_materialized as it was suggested here: https://jira.mariadb.org/browse/MDEV-21883?focusedCommentId=145948&page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel#comment-145948
But it didn't help.
Is there any other information I could provide?



 Comments   
Comment by Elena Stepanova [ 2020-09-21 ]

Could you please paste the output of

SHOW CREATE TABLE books;
SHOW INDEX IN books;
SHOW CREATE TABLE new_topic_resources;
SHOW INDEX IN new_topic_resources;
SHOW CREATE TABLE new_topics;
SHOW INDEX IN new_topics;

and paste or attach your cnf file(s)?
If any of the above are views rather than base tables, then please also include the same output for the underlying tables.

Even better if you can provide a data dump from those tables (that is, if it's not strictly confidential).
If you can do so but don't want to share it publicly, you can upload it to ftp.askmonty.org/private.

Generated at Thu Feb 08 09:22:30 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.