[MDEV-21323] mariabackup crash Created: 2019-12-16  Updated: 2021-06-14  Resolved: 2021-06-14

Status: Closed
Project: MariaDB Server
Component/s: Backup
Affects Version/s: 10.4.7
Fix Version/s: N/A

Type: Bug Priority: Critical
Reporter: Xesh Assignee: Vladislav Vaintroub
Resolution: Incomplete Votes: 0
Labels: need_feedback
Environment:

Centos 7.6.1810


Issue Links:
Duplicate
is duplicated by MDEV-23059 Mariabackup crashed during backup, ma... Closed
Relates
relates to MDEV-21222 mariabackup.incremental_backup failed... Closed

 Description   

When cron script is started backup is crashing every time.

[00] 2019-12-16 07:56:02 Connecting to MySQL server host: localhost, user: root, password: set, port: not set, socket: not set
[00] 2019-12-16 07:56:02 Using server version 10.4.7-MariaDB-log
/bin/mariabackup based on MariaDB server 10.4.7-MariaDB Linux (x86_64)
[00] 2019-12-16 07:56:02 uses posix_fadvise().
[00] 2019-12-16 07:56:02 cd to /var/lib/mysql/
[00] 2019-12-16 07:56:02 open files limit requested 16384, set to 1048576
[00] 2019-12-16 07:56:02 InnoDB: The universal page size of the database is set to 65536.
[00] 2019-12-16 07:56:02 mariabackup: using the following InnoDB configuration:
[00] 2019-12-16 07:56:02 innodb_data_home_dir = /var/lib/mysql
[00] 2019-12-16 07:56:02 innodb_data_file_path = ibdata1:50M;ibdata2:50M:autoextend
[00] 2019-12-16 07:56:02 innodb_log_group_home_dir = ./
[00] 2019-12-16 07:56:02 InnoDB: Using Linux native AIO
2019-12-16 7:56:02 0 [Note] InnoDB: Number of pools: 1
2019-12-16 7:56:02 0 [ERROR] InnoDB: mmap(25769803776 bytes) failed; errno 12
2019-12-16 07:56:02 0x7fcc0afed8c0 InnoDB: Assertion failure in file /home/buildbot/buildbot/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX/mariadb-10.4.7/storage/innobase/include/ut0new.h line 251
InnoDB: Failing assertion: ptr != NULL
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/
InnoDB: about forcing recovery.
191216 7:56:02 [ERROR] mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.

To report this bug, see https://mariadb.com/kb/en/reporting-bugs

We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.

Server version: 10.4.7-MariaDB
key_buffer_size=0
read_buffer_size=131072
max_used_connections=0
max_threads=1
thread_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 5913 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0
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 = 0x0 thread_stack 0x49000
/bin/mariabackup(my_print_stacktrace+0x2e)[0x55934d7a082e]
/bin/mariabackup(handle_fatal_signal+0x30f)[0x55934d293b4f]
sigaction.c:0(__restore_rt)[0x7fcc0abd95d0]
:0(__GI_raise)[0x7fcc08eac207]
:0(__GI_abort)[0x7fcc08ead8f8]
/bin/mariabackup(+0x5a7bc6)[0x55934cefcbc6]
/bin/mariabackup(+0xb85238)[0x55934d4da238]
/bin/mariabackup(+0xb8c42c)[0x55934d4e142c]
/bin/mariabackup(+0x5dc79c)[0x55934cf3179c]
/bin/mariabackup(main+0x185)[0x55934ceffcd5]
/lib64/libc.so.6(__libc_start_main+0xf5)[0x7fcc08e983d5]
/bin/mariabackup(+0x5d3914)[0x55934cf28914]
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...
Working directory at /var/lib/mysql
Resource Limits:
Limit Soft Limit Hard Limit Units
Max cpu time unlimited unlimited seconds
Max file size unlimited unlimited bytes
Max data size unlimited unlimited bytes
Max stack size 8388608 unlimited bytes
Max core file size 0 unlimited bytes
Max resident set unlimited unlimited bytes
Max processes 1048576 1048576 processes
Max open files 1048576 1048576 files
Max locked memory 65536 65536 bytes
Max address space unlimited unlimited bytes
Max file locks unlimited unlimited locks
Max pending signals 381348 381348 signals
Max msgqueue size 819200 819200 bytes
Max nice priority 0 0
Max realtime priority 0 0
Max realtime timeout unlimited unlimited us
Core pattern: core



 Comments   
Comment by Marko Mäkelä [ 2019-12-16 ]

An attempt to allocate of 24 GiB feels too steep to me.

2019-12-16 7:56:02 0 [ERROR] InnoDB: mmap(25769803776 bytes) failed; errno 12

Comment by Xesh [ 2019-12-16 ]

Yes it is trying to allocate 24gb, but in the script it is
/bin/mariabackup --backup --use-memory=4G --target-dir=/mnt/dbbackup_daily/"$BACKUP_DATE"

And even when you run it manually with 1 or 4GB , it is crashing.

Comment by Xesh [ 2019-12-23 ]

The same issue with 10.4.11 version

00] 2019-12-23 07:00:02 Connecting to MySQL server host: localhost, user: root, password: set, port: not set, socket: not set
[00] 2019-12-23 07:00:02 Using server version 10.4.11-MariaDB-log
/bin/mariabackup based on MariaDB server 10.4.11-MariaDB Linux (x86_64)
[00] 2019-12-23 07:00:02 uses posix_fadvise().
[00] 2019-12-23 07:00:02 cd to /var/lib/mysql/
[00] 2019-12-23 07:00:02 open files limit requested 16384, set to 1048576
[00] 2019-12-23 07:00:02 InnoDB: The universal page size of the database is set to 65536.
[00] 2019-12-23 07:00:02 mariabackup: using the following InnoDB configuration:
[00] 2019-12-23 07:00:02 innodb_data_home_dir = /var/lib/mysql
[00] 2019-12-23 07:00:02 innodb_data_file_path = ibdata1:50M;ibdata2:50M:autoextend
[00] 2019-12-23 07:00:02 innodb_log_group_home_dir = ./
[00] 2019-12-23 07:00:02 InnoDB: Using Linux native AIO
2019-12-23 7:00:02 0 [Note] InnoDB: Number of pools: 1
2019-12-23 7:00:02 0 [ERROR] InnoDB: mmap(25769803776 bytes) failed; errno 12
2019-12-23 07:00:02 0x7fb153c3f8c0 InnoDB: Assertion failure in file /home/buildbot/buildbot/padding_for_CPACK_RPM_BUILD_SOURCE_DIRS_PREFIX/mariadb-10.4.11/storage/innobase/include/ut0new.h line 248
InnoDB: Failing assertion: ptr != NULL
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to https://jira.mariadb.org/
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: https://mariadb.com/kb/en/library/innodb-recovery-modes/
InnoDB: about forcing recovery.
191223 7:00:02 [ERROR] mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.

To report this bug, see https://mariadb.com/kb/en/reporting-bugs

We will try our best to scrape up some info that will hopefully help
diagnose the problem, but since we have already crashed,
something is definitely wrong and this may fail.

Server version: 10.4.11-MariaDB
key_buffer_size=0
read_buffer_size=131072
max_used_connections=0
max_threads=1
thread_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 5919 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0
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 = 0x0 thread_stack 0x49000
/bin/mariabackup(my_print_stacktrace+0x2e)[0x55b84c8f337e]
/bin/mariabackup(handle_fatal_signal+0x30f)[0x55b84c3efb5f]
sigaction.c:0(__restore_rt)[0x7fb15382b5d0]
:0(__GI_raise)[0x7fb151afe207]
:0(__GI_abort)[0x7fb151aff8f8]
/bin/mariabackup(+0x5b0574)[0x55b84c05b574]
/bin/mariabackup(+0xb833b8)[0x55b84c62e3b8]
/bin/mariabackup(+0xb8a41c)[0x55b84c63541c]
/bin/mariabackup(+0x5e53dc)[0x55b84c0903dc]
/bin/mariabackup(main+0x185)[0x55b84c05e7d5]
/lib64/libc.so.6(__libc_start_main+0xf5)[0x7fb151aea3d5]
/bin/mariabackup(+0x5dc554)[0x55b84c087554]
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...
Working directory at /var/lib/mysql
Resource Limits:
Limit Soft Limit Hard Limit Units
Max cpu time unlimited unlimited seconds
Max file size unlimited unlimited bytes
Max data size unlimited unlimited bytes
Max stack size 8388608 unlimited bytes
Max core file size 0 unlimited bytes
Max resident set unlimited unlimited bytes
Max processes 1048576 1048576 processes
Max open files 1048576 1048576 files
Max locked memory 65536 65536 bytes
Max address space unlimited unlimited bytes
Max file locks unlimited unlimited locks
Max pending signals 381348 381348 signals
Max msgqueue size 819200 819200 bytes
Max nice priority 0 0
Max realtime priority 0 0
Max realtime timeout unlimited unlimited us
Core pattern: core

Comment by Xesh [ 2019-12-23 ]

I have to restart cluster to make it work, after that it is working

Comment by Marko Mäkelä [ 2020-01-22 ]

This report looks like a possible duplicate of MDEV-21222, which reports an intermittent test failure on our CI platform. While that is about failures to ‘only’ allocate 1GiB, the data set size in our small regression tests should be considerably smaller (way less than 100 megabytes).

Comment by Vladislav Vaintroub [ 2021-05-10 ]

There is not much one can infer from this, due to lack of readable crash callstack.
IF you get a core, can you provide a gdb all threads callstack, please.

and don't use any --use-memory in the backup phase, this does not make sense.

marko, that code you mentioned, always allocates exact 1GB with 64K pages, but never 24G in one go. And it does so on "prepare", not on "backup"

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