[MDEV-11883] MariaDB crashes with out-of-memory when query information_schema Created: 2017-01-23  Updated: 2017-05-16  Resolved: 2017-05-16

Status: Closed
Project: MariaDB Server
Component/s: Admin statements, Server
Affects Version/s: 10.0, 10.1, 10.0.28, 10.2
Fix Version/s: 10.1.24, 10.0.31, 10.2.7

Type: Bug Priority: Major
Reporter: Christian Stern Assignee: Sergei Golubchik
Resolution: Fixed Votes: 0
Labels: None
Environment:

Debian Jessie x86, read-only filesystem

Attachments: File my.cnf    

 Description   

Hi,

I use MariaDB in an embedded Linux system with read-only mounted datadir. Event-Scheduler is DISABLED, so I can start mysqld.

When I query information_schema tables that uses "Open_full_table; Scanned all databases" Extra on select, then the query hangs until an out-of-memory exception occurs. The mysqld daemon is restarted.

Query:

SELECT * FROM information_schema.tables

Exception:

[28200.389724] Out of memory: Kill process 4478 (mysqld) score 612 or sacrifice child [28200.412466] Killed process 4478 (mysqld) total-vm:912336kB, anon-rss:615564kB, file-rss:516kB



 Comments   
Comment by Elena Stepanova [ 2017-01-30 ]

How many tables you have? Or better still, if possible, provide the schema dump – DDL only, without data.
Please also attach your cnf file(s) and paste the output of top (overall values for the system and information for mysqld).after MariaDB server startup, but before you run the query which causes OOM.

Comment by Christian Stern [ 2017-01-30 ]

There is no need to have any tables.

Output of top before mysqld start:

top - 07:11:04 up 3 days, 18:32,  1 user,  load average: 0.15, 0.30, 0.30
 
Tasks: 242 total,   1 running, 240 sleeping,   0 stopped,   1 zombie
 
%Cpu(s):  9.2 us, 15.3 sy,  0.0 ni, 75.5 id,  0.1 wa,  0.0 hi,  0.0 si,  0.0 st
 
KiB Mem:   1007904 total,   652780 used,   355124 free,     4660 buffers
 
KiB Swap:        0 total,        0 used,        0 free.   260420 cached Mem
 
  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
 
 3654 root      10 -10    5528   1660   1264 S   0.0  0.2   0:00.11 mysqld_safe
 
 4182 mysql     10 -10  297312  36788   6860 S   0.0  3.6  10:25.64 mysqld

When the failing query is executed, you can see in top that Memory of mysqld increases.

datadir:

root@Linux:/opt/mysql$ ls -al data
 
total 16
 
4 drwxr-xr-x 4 mysql root 4096 Jan 30 08:27 .
 
4 drwxr-xr-x 8 root    root 4096 Jan 30 08:28 ..
 
0 lrwxrwxrwx 1 mysql root   22 Jan 25 15:01 multi-master.info -> /tmp/multi-master.info
 
4 drwxr-xr-x 2 mysql root 4096 Jan 26 08:48 mysql
 
4 drwxr-xr-x 2 mysql root 4096 Jan 26 08:46 performance_schema

Comment by Christian Stern [ 2017-02-16 ]

@elenst: could you reproduce the error?

Comment by Elena Stepanova [ 2017-02-21 ]

No, I couldn't so far. I haven't even been able start the server on a read-only system.
Could you please attach your error log from the server startup and till OOM?

Comment by Christian Stern [ 2017-02-22 ]

Error log output:

Checking MariaDB database server: is mysqld alive?...no.
 
Starting MariaDB database server: mysqld
 
170222 07:31:29 mysqld_safe Starting mysqld daemon with databases from /opt/mysql/data
 
170222  7:31:29 [Note] /opt/mysql/bin/mysqld (mysqld 10.0.29-MariaDB-0+deb8u1) starting as process 9768 ...
 
170222  7:31:29 [Note] Plugin 'ARCHIVE' is disabled.
 
170222  7:31:29 [Note] Plugin 'FEDERATED' is disabled.
 
170222  7:31:29 [Note] Plugin 'InnoDB' is disabled.
 
170222  7:31:29 [Note] Plugin 'BLACKHOLE' is disabled.
 
170222  7:31:29 [Note] Plugin 'FEEDBACK' is disabled.
 
170222  7:31:29 [Note] Server socket created on IP: '::'.
 
170222  7:31:29 [Note] /opt/mysql/bin/mysqld: ready for connections.
 
Version: '10.0.29-MariaDB-0+deb8u1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  (Debian)
 
...started in 0 seconds.
 
170222  7:36:21 [ERROR] mysqld: Out of memory (Needed 1763424 bytes)
 
170222  7:36:22 [ERROR] Out of memory; check if mysqld or some other process uses all available memory; if not, you may have to use 'ulimit' to allow mysqld to use more memory or you can add more swap space
 
170222  7:36:25 [ERROR] mysqld: Out of memory (Needed 1763424 bytes)
 
170222  7:36:27 [ERROR] Out of memory; check if mysqld or some other process uses all available memory; if not, you may have to use 'ulimit' to allow mysqld to use more memory or you can add more swap space

Other possibility to reproduce: change file permissions of mysql database files: chmod 444 <basedir>/mysql/*
To start mariadb daemon make sure the event-scheduler is DISABLED

Comment by Christian Stern [ 2017-03-10 ]

@elenst: have you found out anything?

Comment by Elena Stepanova [ 2017-03-12 ]

Reproducible as described.

On a release build, memory consumption keeps growing.
A debug build crashes with the assertion failure:

10.0 d04d835f64b39edf0310e0471a7ed261b5cb2a20

 
mysqld: /data/src/10.0/mysys/my_seek.c:58: my_seek: Assertion `fd != -1' failed.
 
170312 18:45:16 [ERROR] mysqld got signal 6 ;
 
 
 
#7  0x00007f2434524312 in __GI___assert_fail (assertion=assertion@entry=0xe91522 "fd != -1", file=file@entry=0xe914b8 "/data/src/10.0/mysys/my_seek.c", 
line=line@entry=58, function=function@entry=0xe91572 <__PRETTY_FUNCTION__.11207> "my_seek") at assert.c:101
 
#8  0x0000000000cc6e95 in my_seek (fd=-1, pos=0, whence=0, MyFlags=0) at /data/src/10.0/mysys/my_seek.c:58
 
#9  0x0000000000b73420 in inline_mysql_file_seek (flags=0, whence=0, pos=0, file=-1, src_line=358, src_file=0xe61468 "/data/src/10.0/storage/csv/ha_tina
 
.cc") at /data/src/10.0/include/mysql/psi/mysql_file.h:1229
 
#10 write_meta_file (meta_file=-1, rows=0, dirty=<optimized out>) at /data/src/10.0/storage/csv/ha_tina.cc:358
 
#11 0x0000000000b741e2 in free_share (share=0x7f2428823470) at /data/src/10.0/storage/csv/ha_tina.cc:422
 
#12 0x0000000000b7443b in ha_tina::open (this=0x7f2428b69088, name=0x7f242885e688 "./mysql/general_log", mode=<optimized out>, open_options=18) at /data/src/10.0/storage/csv/ha_tina.cc:932
 
#13 0x000000000073d467 in handler::ha_open (this=0x7f2428b69088, table_arg=table_arg@entry=0x7f2428897470, name=0x7f242885e688 "./mysql/general_log", mode=mode@entry=2, test_if_locked=test_if_locked@entry=18) at /data/src/10.0/sql/handler.cc:2525
 
#14 0x00000000006664c3 in open_table_from_share (thd=thd@entry=0x7f242a60f070, share=share@entry=0x7f242885e088, alias=<optimized out>, db_stat=db_stat@entry=39, prgflag=prgflag@entry=44, ha_open_flags=18, outparam=0x7f2428897470, is_create_table=false) at /data/src/10.0/sql/table.cc:2865
 
#15 0x000000000056b70c in open_table (thd=thd@entry=0x7f242a60f070, table_list=table_list@entry=0x7f2428b72088, mem_root=mem_root@entry=0x7f2435f32040, ot_ctx=ot_ctx@entry=0x7f2435f32000) at /data/src/10.0/sql/sql_base.cc:2516
 
#16 0x000000000056ce08 in open_and_process_table (new_frm_mem=0x7f2435f32040, ot_ctx=0x7f2435f32000, has_prelocking_list=false, prelocking_strategy=0x7f2435f320e0, flags=1026, counter=0x7f2435f320dc, tables=0x7f2428b72088, lex=0x7f2435f32220, thd=0x7f242a60f070) at /data/src/10.0/sql/sql_base.cc:4034
 
#17 open_tables (thd=thd@entry=0x7f242a60f070, start=start@entry=0x7f2435f320c8, counter=counter@entry=0x7f2435f320dc, flags=flags@entry=1026, prelocking_strategy=prelocking_strategy@entry=0x7f2435f320e0) at /data/src/10.0/sql/sql_base.cc:4568
 
#18 0x000000000056dd37 in open_normal_and_derived_tables (thd=thd@entry=0x7f242a60f070, tables=tables@entry=0x7f2428b72088, flags=1026, dt_phases=dt_phases@entry=34) at /data/src/10.0/sql/sql_base.cc:5283
 
#19 0x0000000000613d4c in fill_schema_table_by_open (thd=thd@entry=0x7f242a60f070, is_show_fields_or_keys=is_show_fields_or_keys@entry=false, table=table@entry=0x7f24288df088, schema_table=schema_table@entry=0x14c28c0 <schema_tables+2048>, orig_db_name=orig_db_name@entry=0x7f2428939b80, orig_table_name=orig_table_name@entry=0x7f2428b55eb0, open_tables_state_backup=0x7f2435f33790, can_deadlock=false) at /data/src/10.0/sql/sql_show.cc:4372
 
#20 0x0000000000627efe in get_all_tables (thd=0x7f242a60f070, tables=<optimized out>, cond=<optimized out>) at /data/src/10.0/sql/sql_show.cc:5033
 
#21 0x00000000006286b4 in get_schema_tables_result (join=join@entry=0x7f24288d7928, executed_place=executed_place@entry=PROCESSED_BY_JOIN_EXEC) at /data/src/10.0/sql/sql_show.cc:8291
 
#22 0x000000000060ca8b in JOIN::exec_inner (this=this@entry=0x7f24288d7928) at /data/src/10.0/sql/sql_select.cc:2543
 
#23 0x000000000060f2f5 in JOIN::exec (this=this@entry=0x7f24288d7928) at /data/src/10.0/sql/sql_select.cc:2378
 
#24 0x000000000060bd8c in mysql_select (thd=thd@entry=0x7f242a60f070, rref_pointer_array=rref_pointer_array@entry=0x7f242a613370, tables=0x7f24288d62b0, wild_num=1, fields=..., conds=0x0, og_num=0, order=0x0, group=0x0, having=0x0, proc_param=0x0, select_options=2684619520, result=0x7f24288d7908, unit=0x7f242a612a08, select_lex=0x7f242a6130f8) at /data/src/10.0/sql/sql_select.cc:3314
 
#25 0x000000000060bf78 in handle_select (thd=thd@entry=0x7f242a60f070, lex=lex@entry=0x7f242a612940, result=result@entry=0x7f24288d7908, setup_tables_done_option=setup_tables_done_option@entry=0) at /data/src/10.0/sql/sql_select.cc:373
 
#26 0x00000000005a9255 in execute_sqlcom_select (thd=thd@entry=0x7f242a60f070, all_tables=0x7f24288d62b0) at /data/src/10.0/sql/sql_parse.cc:5301
 
#27 0x00000000005b0c55 in mysql_execute_command (thd=thd@entry=0x7f242a60f070) at /data/src/10.0/sql/sql_parse.cc:2563
 
#28 0x00000000005b944d in mysql_parse (thd=thd@entry=0x7f242a60f070, rawbuf=<optimized out>, length=39, parser_state=parser_state@entry=0x7f2435f36620) at /data/src/10.0/sql/sql_parse.cc:6583
 
#29 0x00000000005ba9b0 in dispatch_command (command=command@entry=COM_QUERY, thd=thd@entry=0x7f242a60f070, packet=packet@entry=0x7f2432fd9071 "SELECT * FROM information_schema.tables", packet_length=packet_length@entry=39) at /data/src/10.0/sql/sql_parse.cc:1309
 
#30 0x00000000005bc745 in do_command (thd=0x7f242a60f070) at /data/src/10.0/sql/sql_parse.cc:999
 
#31 0x000000000069726e in do_handle_one_connection (thd_arg=thd_arg@entry=0x7f242a60f070) at /data/src/10.0/sql/sql_connect.cc:1377
 
#32 0x000000000069734e in handle_one_connection (arg=0x7f242a60f070) at /data/src/10.0/sql/sql_connect.cc:1292
 
#33 0x00007f2435bb3064 in start_thread (arg=0x7f2435f37700) at pthread_create.c:309
 
#34 0x00007f24345de62d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Comment by Daniel Black [ 2017-03-13 ]

So the table is marked crashed here https://github.com/MariaDB/server/blob/10.0/storage/csv/ha_tina.cc#L247 after the open RDRW fails.

The fix is to test share->meta_file!=-1 before calling write_meta_file/mysql_file_close
https://github.com/MariaDB/server/blob/10.0/storage/csv/ha_tina.cc#L419

To support a read only filesystem, the read_only global will need to determine the open mode and prevent writes in write_meta_file.

Generated at Thu Feb 08 07:53:24 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.