| Bug #82213 | Innodb reports warning while innodb_undo_log_truncate is enabled | ||
|---|---|---|---|
| Submitted: | 13 Jul 2016 9:03 | Modified: | 17 Nov 2017 15:44 |
| Reporter: | zhai weixiang (OCA) | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: InnoDB storage engine | Severity: | S3 (Non-critical) |
| Version: | 5.7, 5.7.13 | OS: | Any |
| Assigned to: | CPU Architecture: | Any | |
[13 Jul 2016 9:03]
zhai weixiang
[13 Jul 2016 9:04]
zhai weixiang
Change category
[14 Jul 2016 8:49]
MySQL Verification Team
Hello Zhai, Thank you for the bug report. I tried with default conf with no luck so far. Could you please provide exact conf file used in your environment, and if possible repeatable test case? Also, noticed similar bugs Bug #50772 / Bug #61567 / Bug #44923 / Bug #62759 and Bug #21685 etc Thanks, Umesh
[14 Jul 2016 9:34]
zhai weixiang
My configure file: [mysqld_safe] pid-file=/u01/my57/run/mysqld.pid [mysql] port=13606 prompt=\\u@\\d \\r:\\m:\\s> default-character-set=utf8 no-auto-rehash [client] port=13606 socket=/u01/my57/run/mysql.sock [mysqld] #dir basedir=/u01/my57 datadir=/u01/my57/data tmpdir=/u01/my57/tmp lc_messages_dir=/u01/my57/share log-error=/u01/my57/log/alert.log slow_query_log_file=/u01/my57/log/slow.log general_log_file=/u01/my57/log/general.log socket=/u01/my57/run/mysql.sock core-file innodb_data_home_dir=/u01/my57/data innodb_log_group_home_dir=/u01/my57/data innodb_data_file_path = ibdata1:4G;ibdata2:16M:autoextend innodb_buffer_pool_size=32G innodb_buffer_pool_instances=8 innodb_buffer_pool_load_at_startup=OFF innodb_page_cleaners=1 innodb_log_files_in_group=4 innodb_log_file_size=4G innodb_log_buffer_size=32M innodb_flush_log_at_trx_commit=2 innodb_max_dirty_pages_pct=60 innodb_thread_concurrency=32 innodb_read_io_threads=4 innodb_write_io_threads=4 innodb_open_files=60000 innodb_file_per_table=1 innodb_flush_method=O_DIRECT innodb_adaptive_flushing=ON innodb_flush_neighbors=0 innodb_old_blocks_time=1000 innodb_stats_on_metadata=0 innodb_read_ahead_threshold=0 innodb_use_native_aio=1 innodb_rollback_on_timeout=0 innodb_purge_threads=1 innodb_strict_mode=1 transaction-isolation=READ-COMMITTED innodb_disable_sort_file_cache=ON innodb_io_capacity_max=6000 innodb_io_capacity=2000 innodb_lru_scan_depth=2048 innodb_undo_tablespaces=20 innodb_sync_array_size=16 innodb_print_all_deadlocks innodb_checksum_algorithm=CRC32 #myisam myisam_sort_buffer_size=64M delayed_insert_timeout=300 #binlog #log-bin=/u01/my57/log/mysql-bin server_id=3017441834 binlog_cache_size=32K max_binlog_cache_size=2G max_binlog_size=500M binlog-format=ROW sync_binlog=1000 log-slave-updates=1 expire_logs_days=0 max_allowed_packet=128M #server port=13606 skip-name-resolve skip-ssl skip-external-locking max_connections=21000 max_user_connections=20200 show_compatibility_56=ON character-set-server=utf8 open_files_limit=65536 local-infile=1 performance_schema=OFF performance_schema_instrument='%=ON' query_cache_type=0 #replication master-info-file=/u01/my57/log/master.info relay-log=/u01/my57/log/relaylog relay_log_info_file=/u01/my57/log/relay-log.info relay-log-index=/u01/my57/log/mysqld-relay-bin.index slave_load_tmpdir=/u01/my57/tmp slave_type_conversions="ALL_NON_LOSSY" slave_net_timeout=4 skip-slave-start sync_master_info=1000 sync_relay_log_info=1000 rpl_stop_slave_timeout=300 slave_checkpoint_group=1024 slave_checkpoint_period=300 slave_parallel_workers=8 #slave_pr_mode=TABLE slave_pending_jobs_size_max=1073741824 slave_rows_search_algorithms='TABLE_SCAN,INDEX_SCAN,HASH_SCAN' slave_sql_verify_checksum=OFF master_verify_checksum=OFF gtid_mode=OFF master_info_repository=TABLE relay_log_info_repository=TABLE connect_timeout=8 net_read_timeout=30 net_write_timeout=60
[14 Jul 2016 9:37]
zhai weixiang
Enable truncating undo log online: innodb_max_undo_log_size = 104857600 innodb_undo_log_truncate = ON
[14 Jul 2016 9:47]
zhai weixiang
This issue should be very easy to repeat: First start a read only transaction: set session tx_isolation = 'REPEATABLE-READ'; begin; select * from sbtest1 limit 1; -- keep the read view open Then start sysbench, and run for a while until the history list of purge system is big enough (in my test, it's bigger than 6,000,000), and the size of most undo tablespaces exceed the configured value of innodb_max_undo_log_size Then commit the transaction, wait, and check the error log
[14 Jul 2016 9:53]
MySQL Verification Team
Thank you for the conf, and repeatable steps. Thanks, Umesh
[14 Jul 2016 12:45]
MySQL Verification Team
Thank you Zhai, fully verified! Thanks, Umesh
[14 Jul 2016 12:45]
MySQL Verification Team
test results
Attachment: 82213.log (application/octet-stream, text), 7.94 KiB.
[14 Jul 2016 12:49]
MySQL Verification Team
-- extract from error log 2016-07-14T12:35:52.129916Z 0 [Warning] InnoDB: Purge reached the head of the history list, but its length is still reported as 4986877! Make a detailed bug report, and submit it to http://bugs.mysql.com 2016-07-14T12:35:52.130144Z 0 [Warning] InnoDB: Purge reached the head of the history list, but its length is still reported as 4986877! Make a detailed bug report, and submit it to http://bugs.mysql.com 2016-07-14T12:35:52.130213Z 0 [Warning] InnoDB: Purge reached the head of the history list, but its length is still reported as 4986877! Make a detailed bug report, and submit it to http://bugs.mysql.com 2016-07-14T12:35:52.139922Z 0 [Warning] InnoDB: Purge reached the head of the history list, but its length is still reported as 4986590! Make a detailed bug report, and submit it to http://bugs.mysql.com 2016-07-14T12:35:52.139951Z 0 [Warning] InnoDB: Purge reached the head of the history list, but its length is still reported as 4986590! Make a detailed bug report, and submit it to http://bugs.mysql.com 2016-07-14T12:39:38.167624Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 1 2016-07-14T12:39:38.345560Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 1 2016-07-14T12:44:38.365546Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 2 2016-07-14T12:44:38.572898Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 2 2016-07-14T12:44:38.573521Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 3 2016-07-14T12:44:38.813712Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 3 2016-07-14T12:44:38.814294Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 4 2016-07-14T12:44:39.008712Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 4 2016-07-14T12:44:39.009223Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 5 2016-07-14T12:44:39.200847Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 5 2016-07-14T12:44:39.201413Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 6 2016-07-14T12:44:39.389119Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 6 2016-07-14T12:44:39.389451Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 7 2016-07-14T12:44:39.573908Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 7 2016-07-14T12:44:39.574459Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 8 2016-07-14T12:44:39.755463Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 8 2016-07-14T12:44:39.755965Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 9 2016-07-14T12:44:39.933955Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 9 2016-07-14T12:44:39.934462Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 10 2016-07-14T12:44:40.111639Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 10 2016-07-14T12:44:40.112197Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 11 2016-07-14T12:44:40.285415Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 11 2016-07-14T12:44:40.285876Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 12 2016-07-14T12:44:40.457220Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 12 2016-07-14T12:44:40.457772Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 13 2016-07-14T12:44:40.620059Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 13 2016-07-14T12:44:40.620408Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 14 2016-07-14T12:44:40.781081Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 14 2016-07-14T12:44:40.781779Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 15 2016-07-14T12:44:40.937669Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 15 2016-07-14T12:44:40.938389Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 16 2016-07-14T12:44:41.088592Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 16 2016-07-14T12:44:41.089097Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 17 2016-07-14T12:44:41.237917Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 17 2016-07-14T12:44:41.238486Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 18 2016-07-14T12:44:41.376476Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 18 2016-07-14T12:44:41.376965Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 19 2016-07-14T12:44:41.512410Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 19 2016-07-14T12:44:41.512990Z 0 [Note] InnoDB: Truncating UNDO tablespace with space identifier 20 2016-07-14T12:44:41.645945Z 0 [Note] InnoDB: Completed truncate of UNDO tablespace with space identifier 20
[17 Nov 2017 15:44]
Daniel Price
Posted by developer: Fixed as of the upcoming 5.5.59, 5.6.39, 5.7.21, 8.0.4 release, and here's the changelog entry: While innodb_undo_log_truncate was enabled, warnings that should only appear in a debug version of MySQL were printed to the error log when the length of the history list exceeded 2000000.
[15 Jan 2018 12:37]
Daniel Price
Posted by developer: Revised changelog entry: Warnings that should only appear in a debug version of MySQL were printed to the error log when the length of the history list exceeded 2000000.
