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

Segfault when using --rows on large dbs with 0.12 #848

Closed
Dansthunder opened this issue Oct 5, 2022 · 35 comments · Fixed by #859, #866, #870, #875 or #880
Closed

Segfault when using --rows on large dbs with 0.12 #848

Dansthunder opened this issue Oct 5, 2022 · 35 comments · Fixed by #859, #866, #870, #875 or #880

Comments

@Dansthunder
Copy link

Hello,

I've just updated mydumper and ran into some issues. Am I missing a flag or doing something wrong?

Results in: ./test.sh: line 24: 4865 Segmentation fault (core dumped) /usr/src/scripts/mydumper/mydumper --database=$DB_NAME --host=$DB_HOST --user=$DB_USER --password=$DB_PASS --outputdir=$DB_DUMP --threads=12 --rows=20000 --compress --triggers --events --routines --verbose=3

On my latest test server, RHEL 9.0, Linux 5.14.0-70.13.1.el9_0.aarch64
[root@rhel9 mydumper]# ./mydumper -V
mydumper 0.12.8, built against MySQL 10.8.5-MariaDB

I'm passing the following and this works, but takes forever, since using chunks, each thread becomes single threaded on large tables in the DB. Tables are ~79GB in size.

--database=$DB_NAME
--host=$DB_HOST
--user=$DB_USER
--password=$DB_PASS
--outputdir=$DB_DUMP
--threads=12
--chunk-filesize=50
--compress
--triggers
--events
--routines
--verbose=3

This USED to work, (and still does on the last of the 11 series -- mydumper 0.11.6, built against MySQL 10.8.5)
--database=$DB_NAME
--host=$DB_HOST
--user=$DB_USER
--password=$DB_PASS
--outputdir=$DB_DUMP
--rows=20000
--compress
--threads=12
--triggers
--events
--routines
--verbose=3

Process of elimination, removing triggers, events, routines, verbose, threads, etc, did nothing. Only until adding chunk solves it. It's ONLY on this large database with very large tables. Works fine on all the other smaller databases with smaller tables. v0.12.5-3 had memory leak issues that silently died after eating all the swap on the server. v0.12.7-1, -2, -3 & v0.12.8 segfault with --rows= on a DB with large tables.

I've had to roll back v0.11.6 for now to regain --rows capability.

--chunk-filesize=20 \ with mydumper 0.12.8
real 99m8.901s
user 35m52.131s
sys 0m27.496s

--rows=20000 \ with mydumper 0.11.6
real 8m39.193s
user 36m11.394s
sys 0m33.158s

Thanks!

@davidducos
Copy link
Member

@Dansthunder
We will need the core dump https://github.com/mydumper/mydumper/wiki/Support#core-dump to perform the investigation.

@Dansthunder
Copy link
Author

Dansthunder commented Oct 5, 2022

Ok, easy enough. Eyeballing it, it appears to dying on a table with binary data?!? I tested with --hex-blob, to see if that made a difference, and it didn't.

Thanks again!

@davidducos
Copy link
Member

@Dansthunder I need you to run:

Run ulimit -c unlimited before starting my program
Run sudo sysctl -w kernel.core_pattern=/tmp/core-%e.%p.%h.%t

then upload the file with the core dump located in /tmp/ under the template name: core-%e.%p.%h.%t

@davidducos davidducos added this to the Release 0.12.9-1 milestone Oct 6, 2022
@davidducos
Copy link
Member

Oh god, I have just realized of aarch64. Nah, no way, I'm not going to be able to troubleshoot or review this in the short term.

@davidducos
Copy link
Member

davidducos commented Oct 6, 2022

I tried to simulate your scenario with this:

sysbench /usr/share/sysbench/oltp_insert.lua --tables=10 --table-size=1000000 --threads=4 --mysql-db=sbtest prepare
sysbench /usr/share/sysbench/oltp_insert.lua --tables=10 --table-size=1000000 --threads=4 --mysql-db=sbtest2 prepare

And executing mydumper like this:

rm -rf data ; ./mydumper --defaults-file=/tmp/empty -u root -v 4 -B sbtest,sbtest2 -h 127.0.0.1 -u root -R -E -o data -c -r 10000 -t 12

But it is working, no segfault.

@Dansthunder
Copy link
Author

Can you tell which table it's failing on exactly in my logs? Maybe I can get an explain or something? Delete some data, optimize, recreate?

I'd guess probably a couple of hundred tables, and we're guessing it's the table with binary data in it. The difference between v0.11 and v0.12 of mydumper is too large for me to make guesses on, as to why one works, and the other doesn't.

Easy solution for now is for me to just stick with v0.11 assuming it's doing everything correctly. Both compile with no issues, and I'm doing a cmake . -DWITH_SSL=OFF and make.

I'm running an mysqlcheck -o on the testbox and letting it optimize every single table which will take a bit to say the least. If there's any change after the optimize, I'll let you know.

Thanks!

@davidducos
Copy link
Member

Hi @Dansthunder ,

https://www.ringerhq.com/i/mydumper/mydumper is an alternative to fix this kind of issues faster.

@Dansthunder
Copy link
Author

@davidducos I deleted over 100 million rows out of two of the tables last night, down from 302 million down to 194 million, still segfaults. Full optimization of the entire database didn't help, other than saving some disk space.

We've reverted back to v0.11.6, and look forward to future releases. Thanks for your time and effort!

@davidducos
Copy link
Member

@Dansthunder
I need you to test https://github.com/mydumper/mydumper/releases/tag/v0.13.0-1 to close this issue.

@Dansthunder
Copy link
Author

Dansthunder commented Oct 25, 2022

Didn't segfault immediately like previously, ran for a smidge then died. Mydumper v0.11.6 has been working past few weeks, no issues.

./amx-test.sh: line 26: 2525 Segmentation fault (core dumped) /usr/src/scripts/mydumper-0.13.0-1/mydumper --database=$DB_NAME --host=$DB_HOST --user=$DB_USER --password=$DB_PASS --outputdir=$DB_DUMP --rows=20000 --threads=8 --build-empty-files --compress --triggers --events --routines --logfile=/var/log/backups/$DOW.dw-db.$DB_NAME.log --verbose=3

@davidducos
Copy link
Member

@Dansthunder can you run this in a x86-64 architecture please?

@Dansthunder
Copy link
Author

Dansthunder commented Oct 26, 2022

None of our servers are x86-64. We're 100% running on aarch64 Graviton2 or Graviton3 C6GN or C7G Amazon EC2 instances. The performance gain in MariaDB moving to Graviton3 in addition to cost savings prohibit migrating backwards to x86-64, either Intel or AMD. We haven't touched x86-64 in about 3+ years now.

But, out of curiosity... Why not spin this up, move the data volume over, and see wtf happens? Same exact thing.

[root@rhel9-x86 tmp]# uname -a
Linux rhel9-x86.va.test.box 5.14.0-70.26.1.el9_0.x86_64 #1 SMP PREEMPT Fri Sep 2 16:07:40 EDT 2022 x86_64 x86_64 x86_64 GNU/Linux

[root@rhel9-x86 ~]# ./amx-test.sh
./amx-test.sh: line 26: 40851 Segmentation fault (core dumped) /usr/src/scripts/mydumper-0.13.0-1/mydumper --database=$DB_NAME --host=$DB_HOST --user=$DB_USER --password=$DB_PASS --outputdir=$DB_DUMP --rows=20000 --threads=8 --build-empty-files --compress --triggers --events --routines --logfile=/var/log/backups/$DOW.dw-db.$DB_NAME.log --verbose=3

@davidducos davidducos linked a pull request Oct 26, 2022 that will close this issue
@davidducos
Copy link
Member

Hi @Dansthunder,
Good to hear the you move to aarch64. MyDumper doesn't have the resources to build with current process or the time nor knowledge to use other alternatives at this point. However, we are willing to implement next year to give better support to all the users.
BTW, you don't need to move the data volume, you only need to spin up a new instance and connect remotely.
Thanks for the file! for sure, something really strange is happening. From the core dump I saw this:

#0  0x00000000004169a6 in random_int_function_with_mem (r=0x0, mem=0x7f249000873f) at /root/pp/mydumper/src/mydumper_masquerade.c:39
#1  0x00007f24a8009890 in ?? ()
#2  0x0000000000ceaaf0 in ?? ()
#3  0x00007f24a405e8f0 in ?? ()
#4  0x00000000004143ef in build_lock_tables_statement (conf=0x0) at /root/pp/mydumper/src/mydumper_working_thread.c:867
#5  0x00007f24a8003770 in ?? ()
#6  0x000000000000000b in ?? ()
#7  0x00000000004146ab in process_integer_chunk (td=0x7f24a8009890, tj=0xd06d90) at /root/pp/mydumper/src/mydumper_working_thread.c:911
#8  0x0000000000415c3c in dump_database_thread (conn=0x7f24ba67e3f0, conf=0x0, database=0x414845 <process_partition_chunk+181>)
    at /root/pp/mydumper/src/mydumper_working_thread.c:1403
#9  0x0000000000000000 in ?? ()

Up to frame 7 is ok, lower frames, are bulls%&t, can you check again with master as I merge #866 which might solve this issue.

@davidducos davidducos reopened this Oct 26, 2022
@Dansthunder
Copy link
Author

Dansthunder commented Oct 26, 2022

Same. I get ~280meg dumped, does fine on the smaller tables, and when it finally hits the big one, it segfaults. Same amount dumped prior to this master version.

@davidducos
Copy link
Member

Hi @Dansthunder,
Thanks for the new coredump. I reviewed a bit further and I found this:

#7  0x00000000004146ab in process_integer_chunk (td=0x7f893c006750, tj=0x1d01d90) at /root/pp/mydumper/src/mydumper_working_thread.c:911
#8  0x0000000000415c3c in dump_database_thread (conn=0x7f894f16e3f0, conf=0x0, database=0x414845 <process_partition_chunk+181>)
    at /root/pp/mydumper/src/mydumper_working_thread.c:1403
#9  0x0000000000000000 in ?? ()
(gdb) f 7
#7  0x00000000004146ab in process_integer_chunk (td=0x7f893c006750, tj=0x1d01d90) at /root/pp/mydumper/src/mydumper_working_thread.c:911
911	    dbt->chunks=NULL;
(gdb) p dbt->database->name
$1 = 0x1d01d70 "amx"
(gdb) p dbt->table
$2 = 0x7f893405ec40 "rtx_pages"
(gdb) p dbt->chunk_type
$3 = CHAR

Why I'm pointing that out? well, in frame 7 we are in funciton process_integer_chunk which is only called if dbt->chunk_type is INTEGER on function thd_JOB_DUMP. However, dbt->chunk_type is CHAR, makes no sense.

I think that you are sending me coredumps that I'm not able to review properly. So I will ask you one more thing, I need you to execute this:

dbg ./mydumper -c core-mydumper.4770.rhel9-x86.va.test.box.1666824803
bt

And then we might be able to understand what is going on.
BTW, is it possible for you to use the binaries from the packages instead of compiling yourself?

@davidducos
Copy link
Member

@Dansthunder I think that I found the issue, just to be 100% sure, can you share the table structure of table amx.rtx_pages? or the last table that is failing? as I think that it has a VARCHAR primary key.

@Dansthunder
Copy link
Author

Dansthunder commented Oct 27, 2022

Reading symbols from ./mydumper...
[New LWP 4781]
[New LWP 4774]
[New LWP 4777]
[New LWP 4780]
[New LWP 4770]
[New LWP 4782]
[New LWP 4773]
[New LWP 4775]
[New LWP 4772]
[New LWP 4779]
[New LWP 4778]
[New LWP 4776]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/src/scripts/mydumper-0.13.0-1/mydumper --database=amx --host=localhost --u'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 get_max_char (conn=, dbt=dbt@entry=0x7f893405e9c0, field=, min=) at /usr/src/scripts/mydumper/src/mydumper_chunks.c:74
74 gchar * r = g_strdup(row[0]);
[Current thread is 1 (Thread 0x7f89457fa640 (LWP 4781))]
(gdb) bt
#0 get_max_char (conn=, dbt=dbt@entry=0x7f893405e9c0, field=, min=) at /usr/src/scripts/mydumper/src/mydumper_chunks.c:74
#1 0x00000000004143ef in process_char_chunk (td=td@entry=0x1ce5af0, tj=tj@entry=0x7f893c006750) at /usr/src/scripts/mydumper/src/mydumper_working_thread.c:926
#2 0x00000000004146ab in thd_JOB_DUMP (td=0x1ce5af0, job=0x7f893c0029e0) at /usr/src/scripts/mydumper/src/mydumper_working_thread.c:478
#3 0x0000000000414845 in process_job (td=, job=0x7f893c0029e0) at /usr/src/scripts/mydumper/src/mydumper_working_thread.c:793
#4 0x0000000000415c3c in process_queue (f=, p=0x414810 <process_job>, resume_mutex=, td=0x1ce5af0, queue=0x1d01d90) at /usr/src/scripts/mydumper/src/mydumper_working_thread.c:857
#5 working_thread (td=0x1ce5af0) at /usr/src/scripts/mydumper/src/mydumper_working_thread.c:1011
#6 0x00007f894f91fd72 in g_thread_proxy (data=0x7f8948003aa0) at ../glib/gthread.c:826
#7 0x00007f894f16e6c2 in start_thread (arg=) at pthread_create.c:443
#8 0x00007f894f10e3f0 in clone3 () at ../sysdeps/unix/sysv/linux/x86_64/clone3.S:81
(gdb)

I was trying to keep things the same...compiling from source, since I'd have to do that on aarch64. Since SOMEONE doesn't provide rpms for errr, the right flavor. :)

Explain attached.

@davidducos
Copy link
Member

Hahaha... I think that SOMEONE is not going to help you anymore! Hahaha...

For sure, we need help to push #835 to have those packages available ASAP.

Ok, about the issue, yeah... I know what is the problem... I'm going to move chunking by CHAR to experimental until we found a good way of implementing it.

@davidducos davidducos linked a pull request Nov 1, 2022 that will close this issue
@davidducos
Copy link
Member

Ok, I have been working during the weekend on it and after understand where was the issue, I was able to fix it. I changed A LOT of things, so be careful.

@davidducos davidducos reopened this Nov 1, 2022
@davidducos davidducos linked a pull request Nov 3, 2022 that will close this issue
@davidducos
Copy link
Member

Hi @Dansthunder, do you have any feedback?

@Dansthunder
Copy link
Author

Yeah. So, not getting a segfault. Backup runs, but on my EC2 image, the x86 box has 16g of ram and 32g of swap and it eats all of it's memory and swap and hard locks. First time I ran, thought my ssh session died. So give me a bit here. For before it ran away, it looked like mariadb was the one using all the memory, not mydumper, which would be odd. Nothing changed in my.cnf.

@Dansthunder
Copy link
Author

Grrr... Takes forever to reboot a hung EC2. Switched back over to the ARM EC2. Running backup right now on arm EC2 instance, 32G / 64G swap, see if it barfs here. May have overwhelmed the AMD x86-64 8 core / 16G box. Running on the ARM box, no runaway memory issues. box sitting with 9G ram free.

It's running. But is it chunking vs using rows? Backup is now 15+ mins in, and 5.2GB done.

Here's v11.5.3 backup time for AMX DB:
Started dump at: 2022-10-31 05:12:26
Finished dump at: 2022-10-31 05:23:54
11GB

11 mins.

@Dansthunder
Copy link
Author

FYI:
/usr/src/scripts/mydumper/mydumper --version
mydumper0.12.8, built against MySQL 10.8.5 with GZIP
Started dump at: 2022-11-03 23:46:13
Finished dump at: 2022-11-04 00:09:56

Same test EC2, older version:
mydumper 0.11.6, built against MySQL 10.8.5
Started dump at: 2022-11-04 00:16:20
Finished dump at: 2022-11-04 00:36:25

Linux dw-rhel9.va.test.box 5.14.0-70.13.1.el9_0.aarch64 #1 SMP Thu Apr 14 12:36:51 EDT 2022 aarch64 aarch64 aarch64 GNU/Linux

New mydumper was off fresh boot, and old version was obviously run after the first, so MariaDB could be running off of cache. 25 mins vs 15 mins vs 11 mins production. But no segfault! :)

@davidducos
Copy link
Member

Hi @Dansthunder,
Love to hear the there is no segfault issue, was not easy to find out the memory leak.
I acknowledge the performance issue, I kind of expect it. I think that we can fix it but I need to perform a couple of tests to be sure.
FYI, the problem that I'm dealing is how to split the PK based on CHAR, which in your case is not an issue as you are using binaries, but for mydumper is the same, and the problem with CHAR is the character set as I might end up in an invalid string. So, I need to test what happen in this scenarios.

@davidducos
Copy link
Member

I have been working on another approach and I found that --rows will not be the kind of parameter that we need for 'character' splitting. I will be adding --char-deep and --char-chunks, where deep is based on the new strategy of how we split a table, we start with a table with MIN and MAX at deep 0, thread 1 (t1) is going to take that job, then when t2 arrives and t1 will change the max to MIN + (MAX-MIN)/2, which is going to be the min for t2. Now, we have 2 jobs from [ MIN , MIN + (MAX-MIN)/2 ] and [ MIN + (MAX-MIN)/2 , MAX ] both at deep 1. Every time that a job is splitted, the deep increases. --char-deep will limit the deep, which at the ends means how many times a chunk can be splitted.
Once that we have a job, we need to determine how many chunk we want in it, as we need to leave some pieces for other threads to export. We can use --char-chunks to do that.

@davidducos davidducos reopened this Nov 9, 2022
@davidducos davidducos linked a pull request Nov 9, 2022 that will close this issue
@christianjoun
Copy link

I am also running into this segmentation fault. I looked in the schema and saw a table that is using a VARCHAR as a primary key. I tried to exclude this table but received another segmentation error. This is what I am running and the version of the software.

mydumper
--database=$DB_NAME
--host=$DB_HOST
--user=$DB_USER
--password=$DB_PASS
--outputdir=$DB_DUMP
--rows=1000000
--compress
--build-empty-files
--threads=8
--compress-protocol
--routines
-L /home/ec2-user/logs/mydumper-logs.txt
--kill-long-queries
--order-by-primary
--long-query-guard 3600
--trx-consistency-only
--regex='^(?!(dbname.user$))'
-v 3

mydumper --version
mydumper 0.12.7-3, built against MySQL 5.7.39-42

I get this around 21gb of dumped data each time. (./script.sh: line 32: 2905 Segmentation fault)

@davidducos
Copy link
Member

@christianjoun Why don't you test with master compiling your self.
@Dansthunder , it should be ok for you to test.

@Dansthunder
Copy link
Author

Ok, instead of --rows, now I'm using --char-chunks and say --char-deep=8 ?

@davidducos
Copy link
Member

@Dansthunder you need to use --rows!! --char-chunks and --char-deep is for tuning, you can leave the default values.

@Dansthunder
Copy link
Author

Ok using same exact script using --rows: I didn't add the --char-chunks or --char-deep. So we're back to the exact same perf as v0.11.6, 20 mins. This is just a default GP3 drive, not the max perf that we run in production on this test box.

mydumper0.12.8, built against MySQL 10.8.5 with GZIP

Started dump at: 2022-11-09 19:50:44
Finished dump at: 2022-11-09 20:10:04

@davidducos
Copy link
Member

davidducos commented Nov 9, 2022

@Dansthunder ok, this is good, but I'm wondering if we are chunking by CHAR and how it is being split. Is it possible for you to share the log? as I need to check the where clause per chunk.

@davidducos
Copy link
Member

@Dansthunder try again with --rows=1000:100000:10000000

@Dansthunder
Copy link
Author

Number of rows doesn't make a difference. I was capped on EC2 drive speed. I maxed out drive spec, and changed threads from 8, to 16, 24, 32, and 64. I was running another shell, watching iotop, and no matter what I did, I was flat lining mariadb read speeds. Let's try and break this thing, and give DavidDucos something to fix. (never crashed no matter how many threads --aawww shucks)

This is a 16 core arm64 EC2 Amazon EC2 c7g.4xlarge, Maxing out a GP3 drive to 16,000 IOPs and 1000 MiB/s 32 threads, dropped the previous 20 minute run down to 10, and 64 threads down to 8, with rows=50000. There's one smaller table at the end that's holding up this 8 minute run, that could probably benefit from a smaller rows=xxxx, but I don't feel like waiting again.

Started dump at: 2022-11-10 00:52:18
Finished dump at: 2022-11-10 00:59:59

How we settled on 8 threads... used to be 12, then 8. Obviously, prod only reboots when something bad happens. So after maybe 3-6 months of backups, mariadb would segfault during a backup -- out of memory or whatever. This is going back year(s). Reducing it down to 8, no issues, box lives, no out of memory crashes. So while on the test box 16+ work, seriously doubt I'd trust it, just so a backup runs 2 mins faster.

@davidducos davidducos linked a pull request Nov 10, 2022 that will close this issue
@davidducos
Copy link
Member

Hi @Dansthunder,
BTW, did you try the ZSTD package? it will reduce IOPS, disk space usage and it is not going to take longer.
I push a last fix, please try again with --rows=100:1000:10000000, now it should be able to adapt the amount of rows in the chunks based on the query time, less than 1 second increases and more than 2 seconds decreases.

@Dansthunder
Copy link
Author

with --rows=20000, --threads=8 w/zstd. I had to go digging thru the past comments to figure out how to enable it. :)
Started dump at: 2022-11-10 20:41:39
Finished dump at: 2022-11-10 20:46:40

with --threads=8, that's just on the verge of maxing out disk IO read limits on EC2 / GP3 max settings. I can only read so fast from MariaDB. I can go --threads-10, 12, 16, etc, instantly maxed out, and no diff in time. We'd have to move outta the "Normal" NVME GP3 drives and step up to IO2 or IO2 Block Express for insane speeds. Boss ain't paying for that.

zstd is the way to go. :)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment