[#MDEV-32088] ibdata1 grows in size for ~17GB daily

[MDEV-32088] ibdata1 grows in size for ~17GB daily Created: 2023-09-04 Updated: 2024-02-07 Resolved: 2024-02-07
Status:	Closed
Project:	MariaDB Server
Component/s:	Galera
Affects Version/s:	11.0.2
Fix Version/s:	N/A

Type:

Bug

Priority:

Major

Reporter:

David Pivonka

Assignee:

Marko Mäkelä

Resolution:

Incomplete

Votes:

0

Labels:

mariadb

Attachments:

screenshot-1.png

Description

We upgraded our MariaDB instance from 10.4 to 11.0.2 and from this time our ibdata1 file started to grow in size by ~17GB per day.

We are currently using MariaDB 11.0.2 with Galera. Our datadir size 2.2TB. We have innodb_file_per_table turned ON and we also used innodbchecksum tool to investigate what’s going on in ibdata - it looks like everything is filled with undo logs, please see here:

"checksum.txt" 61L, 1654B 1,0-1 All

File::ibdata1
================PAGE TYPE SUMMARY==============
#PAGE_COUNT PAGE_TYPE
===============================================
1180 Index page
17935695 Undo log page
63539 Inode page
568 Insert buffer free list page
8206274 Freshly allocated page
1600 Insert buffer bitmap
152 System page
1 Transaction system page
1 File Space Header
1614 Extent descriptor page
0 BLOB page
0 Compressed BLOB page
0 Page compressed page
0 Page compressed encrypted page
0 Other type of page

===============================================
Additional information:
Undo page type: 17935695
Undo page state: 0 active, 120 cached, 5406344 to_purge, 0 prepared, 12529231 other
index_id #pages #leaf_pages #recs_per_page #bytes_per_page
1 3 2 104 9109
2 17 16 146 9702
3 6 5 130 10167
4 5 4 187 8241
5 1 1 320 13725
11 1 1 0 0
12 1 1 0 0
13 1 1 0 0
14 1 1 0 0
15 3 2 98 5783
16 1 0 2 32
17 1 1 0 0
1046 3 3 760 11410
1047 9 9 816 12251
1106 3 3 1126 15071
63258842 29 29 526 8101

index_id page_data_bytes_histgram(empty,...,oversized)
1 0 1 0 0 0 0 0 0 1 1 0 0
2 0 1 0 0 1 3 2 5 3 1 1 0
3 0 1 0 0 0 0 0 1 3 1 0 0
4 0 1 0 0 0 1 0 1 2 0 0 0
5 0 0 0 0 0 0 0 0 0 1 0 0
11 1 0 0 0 0 0 0 0 0 0 0 0
12 1 0 0 0 0 0 0 0 0 0 0 0
13 1 0 0 0 0 0 0 0 0 0 0 0
14 1 0 0 0 0 0 0 0 0 0 0 0
15 0 1 0 0 0 1 1 0 0 0 0 0
16 0 1 0 0 0 0 0 0 0 0 0 0
17 1 0 0 0 0 0 0 0 0 0 0 0
1046 0 0 0 0 0 0 1 0 2 0 0 0
1047 0 0 0 0 0 0 1 3 2 1 2 0
1106 0 0 0 0 0 0 0 0 0 1 2 0
63258842 0 0 0 0 0 24 5 0 0 0 0 0
-4294967296 0 0 0 0 0 0 0 0 0 0 0 0
~
~
~

It looks like purging of undo logs is not working at all.

This could be still related to: ~~MDEV-31234~~

Comments

Comment by Daniel Black [ 2023-09-04 ]

Does setting innodb_undo_log_truncate=1 help?

Comment by David Pivonka [ 2023-09-05 ]

@Daniel Black it does not. It was set to OFF as expected, so I set it to ON, then I watched ibdata file size. I did not help, ibdata size is still the same.

I also tried to change innodb_purge_rseg_truncate_frequency to 1 to make it purge more often (if I understood it correctly), but there is still none changes in ibdata file size.

I'm including innodb variables below, in case it helps.

This is output of `show variables like "innodb_%";`:

Variable_name	Value
------------------------------------------	------------------------
innodb_adaptive_flushing	ON
innodb_adaptive_flushing_lwm	10.000000
innodb_adaptive_hash_index	OFF
innodb_adaptive_hash_index_parts	8
innodb_autoextend_increment	64
innodb_autoinc_lock_mode	2
innodb_buf_dump_status_frequency	0
innodb_buffer_pool_chunk_size	1610612736
innodb_buffer_pool_dump_at_shutdown	ON
innodb_buffer_pool_dump_now	OFF
innodb_buffer_pool_dump_pct	25
innodb_buffer_pool_filename	ib_buffer_pool
innodb_buffer_pool_load_abort	OFF
innodb_buffer_pool_load_at_startup	ON
innodb_buffer_pool_load_now	OFF
innodb_buffer_pool_size	103079215104
innodb_checksum_algorithm	full_crc32
innodb_cmp_per_index_enabled	OFF
innodb_compression_algorithm	zlib
innodb_compression_default	OFF
innodb_compression_failure_threshold_pct	5
innodb_compression_level	6
innodb_compression_pad_pct_max	50
innodb_data_file_buffering	ON
innodb_data_file_path	ibdata1:12M:autoextend
innodb_data_file_write_through	OFF
innodb_data_home_dir
innodb_deadlock_detect	ON
innodb_deadlock_report	full
innodb_default_encryption_key_id	1
innodb_default_row_format	dynamic
innodb_defragment	OFF
innodb_defragment_fill_factor	0.900000
innodb_defragment_fill_factor_n_recs	20
innodb_defragment_frequency	40
innodb_defragment_n_pages	7
innodb_defragment_stats_accuracy	0
innodb_disable_sort_file_cache	OFF
innodb_doublewrite	ON
innodb_encrypt_log	OFF
innodb_encrypt_tables	OFF
innodb_encrypt_temporary_tables	OFF
innodb_encryption_rotate_key_age	1
innodb_encryption_rotation_iops	100
innodb_encryption_threads	0
innodb_fast_shutdown	1
innodb_fatal_semaphore_wait_threshold	600
innodb_file_per_table	ON
innodb_fill_factor	100
innodb_flush_log_at_timeout	1
innodb_flush_log_at_trx_commit	2
innodb_flush_method	fsync
innodb_flush_neighbors	0
innodb_flush_sync	ON
innodb_flushing_avg_loops	30
innodb_force_primary_key	OFF
innodb_force_recovery	0
innodb_ft_aux_table
innodb_ft_cache_size	8000000
innodb_ft_enable_diag_print	OFF
innodb_ft_enable_stopword	ON
innodb_ft_max_token_size	84
innodb_ft_min_token_size	3
innodb_ft_num_word_optimize	2000
innodb_ft_result_cache_limit	2000000000
innodb_ft_server_stopword_table
innodb_ft_sort_pll_degree	2
innodb_ft_total_cache_size	640000000
innodb_ft_user_stopword_table
innodb_immediate_scrub_data_uncompressed	OFF
innodb_instant_alter_column_allowed	add_drop_reorder
innodb_io_capacity	90000
innodb_io_capacity_max	90000
innodb_lock_wait_timeout	120
innodb_log_buffer_size	536870912
innodb_log_file_buffering	ON
innodb_log_file_size	536870912
innodb_log_file_write_through	OFF
innodb_log_group_home_dir	./
innodb_lru_flush_size	32
innodb_lru_scan_depth	1536
innodb_max_dirty_pages_pct	90.000000
innodb_max_dirty_pages_pct_lwm	0.000000
innodb_max_purge_lag	0
innodb_max_purge_lag_delay	0
innodb_max_purge_lag_wait	4294967295
innodb_max_undo_log_size	10485760
innodb_monitor_disable
innodb_monitor_enable
innodb_monitor_reset
innodb_monitor_reset_all
innodb_old_blocks_pct	37
innodb_old_blocks_time	1000
innodb_online_alter_log_max_size	134217728
innodb_open_files	600
innodb_optimize_fulltext_only	OFF
innodb_page_size	16384
innodb_prefix_index_cluster_optimization	ON
innodb_print_all_deadlocks	ON
innodb_purge_batch_size	300
innodb_purge_rseg_truncate_frequency	128
innodb_purge_threads	4
innodb_random_read_ahead	OFF
innodb_read_ahead_threshold	56
innodb_read_io_threads	16
innodb_read_only	OFF
innodb_read_only_compressed	OFF
innodb_rollback_on_timeout	OFF
innodb_sort_buffer_size	1048576
innodb_spin_wait_delay	4
innodb_stats_auto_recalc	ON
innodb_stats_include_delete_marked	OFF
innodb_stats_method	nulls_equal
innodb_stats_modified_counter	0
innodb_stats_on_metadata	OFF
innodb_stats_persistent	ON
innodb_stats_persistent_sample_pages	20
innodb_stats_traditional	ON
innodb_stats_transient_sample_pages	8
innodb_status_output	OFF
innodb_status_output_locks	OFF
innodb_strict_mode	ON
innodb_sync_spin_loops	30
innodb_table_locks	ON
innodb_temp_data_file_path	ibtmp1:12M:autoextend
innodb_tmpdir
innodb_undo_directory	/vol/data/mysql/undo
innodb_undo_log_truncate	ON
innodb_undo_tablespaces	0
innodb_use_atomic_writes	ON
innodb_use_native_aio	OFF
innodb_write_io_threads	16

This is output of `show status like "innodb_%";`:

Variable_name	Value
--------------------------------------------------	--------------------------------------------------
Innodb_adaptive_hash_hash_searches	0
Innodb_adaptive_hash_non_hash_searches	0
Innodb_background_log_sync	326368
Innodb_buffer_pool_dump_status
Innodb_buffer_pool_load_status	Buffer pool(s) load completed at 230901 13:14:29
Innodb_buffer_pool_resize_status
Innodb_buffer_pool_load_incomplete	OFF
Innodb_buffer_pool_pages_data	6230528
Innodb_buffer_pool_bytes_data	102080970752
Innodb_buffer_pool_pages_dirty	149814
Innodb_buffer_pool_bytes_dirty	2454552576
Innodb_buffer_pool_pages_flushed	766619542
Innodb_buffer_pool_pages_free	0
Innodb_buffer_pool_pages_made_not_young	8194056281
Innodb_buffer_pool_pages_made_young	429837765
Innodb_buffer_pool_pages_misc	0
Innodb_buffer_pool_pages_old	2299921
Innodb_buffer_pool_pages_total	6230528
Innodb_buffer_pool_pages_lru_flushed	2523230
Innodb_buffer_pool_pages_lru_freed	76887708
Innodb_buffer_pool_pages_split	5463147
Innodb_buffer_pool_read_ahead_rnd	0
Innodb_buffer_pool_read_ahead	5414
Innodb_buffer_pool_read_ahead_evicted	14083405
Innodb_buffer_pool_read_requests	83021526688
Innodb_buffer_pool_reads	738201326
Innodb_buffer_pool_wait_free	15018
Innodb_buffer_pool_write_requests	7895493406
Innodb_checkpoint_age	89296383
Innodb_checkpoint_max_age	434147697
Innodb_data_fsyncs	24018014
Innodb_data_pending_fsyncs	0
Innodb_data_pending_reads	0
Innodb_data_pending_writes	0
Innodb_data_read	12094684119040
Innodb_data_reads	738201588
Innodb_data_writes	786895858
Innodb_data_written	25025636941824
Innodb_dblwr_pages_written	760824125
Innodb_dblwr_writes	6003173
Innodb_deadlocks	0
Innodb_history_list_length	3444
Innodb_log_waits	0
Innodb_log_write_requests	7367069514
Innodb_log_writes	14252581
Innodb_lsn_current	65211128002336
Innodb_lsn_flushed	65211127731353
Innodb_lsn_last_checkpoint	65211038705953
Innodb_master_thread_active_loops	0
Innodb_master_thread_idle_loops	326369
Innodb_max_trx_id	8270478575
Innodb_mem_adaptive_hash	0
Innodb_mem_dictionary	612594464
Innodb_os_log_written	368202847032
Innodb_page_size	16384
Innodb_pages_created	7772930
Innodb_pages_read	738201326
Innodb_pages_written	766619542
Innodb_row_lock_current_waits	0
Innodb_row_lock_time	1
Innodb_row_lock_time_avg	0
Innodb_row_lock_time_max	0
Innodb_row_lock_waits	256
Innodb_num_open_files	254
Innodb_truncated_status_writes	0
Innodb_available_undo_logs	128
Innodb_undo_truncations	0
Innodb_page_compression_saved	0
Innodb_num_pages_page_compressed	0
Innodb_num_page_compressed_trim_op	0
Innodb_num_pages_page_decompressed	0
Innodb_num_pages_page_compression_error	0
Innodb_num_pages_encrypted	0
Innodb_num_pages_decrypted	0
Innodb_have_lz4	OFF
Innodb_have_lzo	OFF
Innodb_have_lzma	OFF
Innodb_have_bzip2	OFF
Innodb_have_snappy	OFF
Innodb_have_punch_hole	ON
Innodb_defragment_compression_failures	0
Innodb_defragment_failures	0
Innodb_defragment_count	0
Innodb_instant_alter_column	0
Innodb_onlineddl_rowlog_rows	0
Innodb_onlineddl_rowlog_pct_used	0
Innodb_onlineddl_pct_progress	0
Innodb_encryption_rotation_pages_read_from_cache	0
Innodb_encryption_rotation_pages_read_from_disk	0
Innodb_encryption_rotation_pages_modified	0
Innodb_encryption_rotation_pages_flushed	0
Innodb_encryption_rotation_estimated_iops	0
Innodb_encryption_n_merge_blocks_encrypted	0
Innodb_encryption_n_merge_blocks_decrypted	0
Innodb_encryption_n_rowlog_blocks_encrypted	0
Innodb_encryption_n_rowlog_blocks_decrypted	0
Innodb_encryption_n_temp_blocks_encrypted	0
Innodb_encryption_n_temp_blocks_decrypted	0
Innodb_encryption_num_key_requests	0

Comment by Marko Mäkelä [ 2023-09-06 ]

innodb_undo_log_truncate=ON only has an impact on the undo* files, that is, when innodb_undo_tablespaces>1. In MariaDB Server 11.0, the default was changed to innodb_undo_tablespaces=3 in ~~MDEV-29986~~. Is there a particular reason why the non-default parameter innodb_undo_tablespaces=0 is being used?

Have you monitored the InnoDB history list length and tried to tune the related throttling parameters (~~MDEV-29401~~)?

show global status like 'Innodb_history_list_length';

Comment by David Pivonka [ 2023-09-06 ]

@marko, understood, thanks. innodb_undo_tablespaces is set to 0 because we used MariaDB 10.4 before upgrading to 11.0.2. We tried to set innodb_undo_tablespaces to 3, but it requires innodb_fast_shutdown=0 which we executed and restarted MariaDB, then it took 3 days and it was still going so we killed the process (all this was executed in non-production environment just to test how it behaves).

It looks like grow of ibdata1 file magically stopped on Sunday, see:

We did not perform anything with the DB settings.

It's very strange. Is there any way to purge undologs from ibdata1 manually, without using clean import of DB via mysqldump?

I also added monitoring of Innodb_history_list_length to our system so we can compare values.

Comment by Marko Mäkelä [ 2023-09-06 ]

davidpivonka, thank you. A slow shutdown (innodb_fast_shutdown=0) will do two extra things, compared to the default innodb_fast_shutdown=1:

Complete the merge of any buffered changes to secondary index leaf pages. (I guess that this is not the issue, because this must actually be done as part of a normal upgrade to 11.0; see ~~MDEV-29694~~.)
Complete the purge of history of committed transactions.

I assume that the problem is a very long history list (lots of committed transactions whose history has not been removed). Did you try to execute the slow shutdown on 11.0.2 or 11.0.3? It should output some progress messages to the server error log, I think every 15 minutes. It should be also much faster than the slow shutdown on 10.4, thanks to ~~MDEV-21751~~.

When it comes to shrinking the ibdata1 file once the undo logs have successfully been moved out of it, that would be possible in 11.2, thanks to ~~MDEV-14795~~.

Comment by Marko Mäkelä [ 2024-01-05 ]

davidpivonka, did you try to upgrade to a newer version that includes a fix of ~~MDEV-32050~~? It should allow the history list to shrink much faster.

Generated at Thu Feb 08 10:28:44 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.