Bug #70185 Mysql 5.6.13 - InnoDB: Unable to allocate memory of size 18446744073709546280
Submitted: 29 Aug 2013 18:20 Modified: 23 Jan 2014 0:36
Reporter: Josiah Webb Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S1 (Critical)
Version:5.6.1x OS:Linux (3.4.43-43.43.amzn1.x86_64)
Assigned to: CPU Architecture:Any
Tags: innodb memory buffer

[29 Aug 2013 18:20] Josiah Webb
Description:
InnoDB is trying to allocate the max value for innodb_buffer_pool_size (18446744073709546280 bytes). But i have innodb_buffer_pool_size explicitly set in my.cnf to 25G. 

The server is an Amazon EC2 "cluster compute" instance (flavor: cc2.8xlarge) running generic Amazon Linux. 

The specs are:

Architecture = 64-bit
Memory = 60.50 GB
CPU = 16 core w/ hyper threading

/etc/my.cnf (note the 'innodb_buffer_pool_size=25G'):

[mysqld]

relay-log                       = /media/ephemeral0/binlogs/relay-bin
log-bin                         = /media/ephemeral0/binlogs/bin

# Network
port                        = 3306
# for AWS, where IPs can change, we need to use hostnames
# skip-name-resolve
connect_timeout             = 300
max_connections             = 2000
max_user_connections        = 100
wait_timeout                = 300
max_connect_errors          = 10000
max_allowed_packet          = 1073741824
net_read_timeout            = 300
net_write_timeout           = 600

# Replication
skip-slave-start
server-id                       = 178749930
binlog-format                   = row
binlog_row_image                = minimal
slave_transaction_retries       = 24
slave_exec_mode                 = IDEMPOTENT
replicate-wild-ignore-table     = replication_monitor.%
replicate-wild-ignore-table     = scratch.%
explicit_defaults_for_timestamp
sync_binlog			= 0
slave_parallel_workers          = 100
slave_pending_jobs_size_max     = 536870912

# MyISAM key buffers
# THE FOLLOWING ALL TO BE TUNED
key_buffer_size                                          = 8G
#activity_cache.key_buffer_size                          = 256M
#cons__cons_group_cache.key_buffer_size                  = 256M
#cons_action_contribution_cache.key_buffer_size          = 256M
#cons_action_signup_cache.key_buffer_size                = 256M
#mailing_recipient_click_cache.key_buffer_size           = 512M
#redirect_log_cache.key_buffer_size                      = 256M
#stg_mailing_recipient_click2_cache.key_buffer_size      = 256M
#stg_mailing_recipient_click2_alt_cache.key_buffer_size  = 256M

# Memory allocations
max_heap_table_size         = 512M
#table_open_cache            = 10000
sort_buffer_size            = 4M
#read_buffer_size            = 2M
#read_rnd_buffer_size        = 8M
#tmp_table_size              = 2G
#myisam_sort_buffer_size     = 64M
#join_buffer_size            = 4M
#bulk_insert_buffer_size     = 64M
#thread_cache_size           = 100
query_cache_size            = 0
query_cache_type            = 0
table_definition_cache      = 5000

# Slow logging
log-queries-not-using-indexes
long_query_time                 = 120
min_examined_row_limit          = 50000
slow_query_log

# InnoDB settings
innodb_buffer_pool_size             = 25G
innodb_buffer_pool_instances        = 25
innodb_log_file_size                = 1024M
innodb_flush_log_at_trx_commit      = 0
innodb_file_per_table
# innodb_lazy_drop_table              = 1
innodb_data_file_path               = ibdata1:10M:autoextend
innodb_log_files_in_group           = 2
innodb_file_format                  = Barracuda
innodb_old_blocks_time              = 1000
innodb_stats_on_metadata            = OFF

# SSL config
ssl_cert                            = /var/lib/mysql/ssl/server-cert.pem
ssl_key                             = /var/lib/mysql/ssl/server-key.pem
ssl_ca                              = /var/lib/mysql/ssl/ca.pem

# Miscellaneous configs
log-bin-trust-function-creators = 1
back_log                    = 900
core-file
delayed_queue_size          = 50000
open_files_limit            = 1048576
ft_min_word_len             = 2
event_scheduler
log-warnings = 1
performance_schema

[mysqldump]
quick
max_allowed_packet          = 134217728

[mysql]
no-auto-rehash

[mysqlhotcopy]
interactive-timeout

The error log dislpays:

2013-08-29 17:28:09 11345 [ERROR] InnoDB:  InnoDB: Unable to allocate memory of size 18446744073709546280.

2013-08-29 17:28:09 7f798a66e700  InnoDB: Assertion failure in thread 140159989769984 in file ha_innodb.cc line 16865
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
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: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
17:28:09 UTC - 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.
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.

key_buffer_size=8589934592
read_buffer_size=131072
max_used_connections=0
max_threads=2000
thread_count=0
connection_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 16863748 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 = 0 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x35)[0x8c90d5]
/usr/sbin/mysqld(handle_fatal_signal+0x4a4)[0x65cee4]
/lib64/libpthread.so.0(+0xf8e0)[0x7f8290f0a8e0]
/lib64/libc.so.6(gsignal+0x35)[0x7f828fbbd945]
/lib64/libc.so.6(abort+0x17b)[0x7f828fbbf25b]
/usr/sbin/mysqld[0x8de5cf]
/usr/sbin/mysqld[0x92660f]
/usr/sbin/mysqld[0x926715]
/usr/sbin/mysqld[0x9268fc]
/usr/sbin/mysqld[0x9a695f]
/usr/sbin/mysqld[0x9aaea6]
/usr/sbin/mysqld[0x990735]
/usr/sbin/mysqld[0x97c215]
/usr/sbin/mysqld[0x9d73b2]
/usr/sbin/mysqld[0x97e41d]
/usr/sbin/mysqld[0x97c6a0]
/usr/sbin/mysqld[0x97ce07]
/usr/sbin/mysqld[0x97d99a]
/usr/sbin/mysqld[0x94e216]
/usr/sbin/mysqld[0x9a641b]
/usr/sbin/mysqld[0x996d8f]
/lib64/libpthread.so.0(+0x7c6b)[0x7f8290f02c6b]
/lib64/libc.so.6(clone+0x6d)[0x7f828fc6b5ed]

How to repeat:
Unclear on how to repeat other than build a cc2.8xlarge EC2 instance and setup a database and use the my.cnf i posted above, along with MySQL 5.6.13 x86_64.

Suggested fix:
I can successfully start mysqld by doing either of 2 things.

1) add 'innodb_force_recovery=4' to [mysqld] in my.cnf

or....

2) set 'innodb_change_buffering=none' in my.cnf 

Number 1 does number 2 on it's own as well as disables any innodb table stats. However, just adding 'innodb_stats_persistent=0' to my.cnf alone does *not* fix the problem, so the issues seems to be related to the innodb insert/change buffer. I have tried the exact same data and databases on the same exact EC2 instance using MySQL-server-5.6.10-1.el6.x86_64 as well as MySQL-server-5.6.13-1.el6.x86_64. The results are always the same.

We cannot leave change buffering disabled on our high volume write database.
[29 Aug 2013 19:16] MySQL Verification Team
Looks similar to http://bugs.mysql.com/bug.php?id=70073 please see [19 Aug 5:17] Shane Bester comment. Thanks.
[29 Aug 2013 20:25] Josiah Webb
Thanks for getting back to me on this...

I mentioned that i had already tried that suggested fix:

"However, just adding 'innodb_stats_persistent=0' to my.cnf alone does *not* fix the problem"

Mysql will not start unless i do 1 of the 2 things i mentioned ('innodb_force_recovery=4' or 'innodb_change_buffering=none' in my.cnf). innodb_stats_persistent=0 does nothing for the error.
[29 Aug 2013 21:02] Josiah Webb
Also, to be clear.. the amount of memory that innodb is attempting to allocate is 18446744073709551615 bytes (17 billion GB's), so it's unlikely that it's allocating for innodb stats. It's is likely related to the innodb insert buffer as i described in the "suggested fix" section above.
[29 Aug 2013 21:39] MySQL Verification Team
But you did the 'delete'?:

DELETE FROM mysql.innodb_index_stats;
DELETE FROM mysql.innodb_table_stats;

That stopped the assertion for that reporter. I had hope was the same case because
the assertion printed by InnoDB happens in the same place.
[30 Aug 2013 3:23] Josiah Webb
So the only way mysqld will start is for me to add either 'innodb_force_recovery=4' or 'innodb_change_buffering=none' to my.cnf. I cannot use 'innodb_force_recovery=4' as it prevents me from doing any DELETE statements on innodb tables. So, i added 'innodb_change_buffering=none' to my.cnf and mysqld started, then i ran the delete statements from http://bugs.mysql.com/bug.php?id=70073.

mysql> DELETE FROM mysql.innodb_index_stats;
Query OK, 1112767 rows affected (8.95 sec)

mysql> DELETE FROM mysql.innodb_table_stats;
Query OK, 91044 rows affected (1.99 sec)

Stopped mysqld properly and without any issues. Removed 'innodb_change_buffering=none' from my.cnf and started mysqld back up.

Same exact error... same exact place:

2013-08-30 03:14:20 4532 [ERROR] InnoDB:  InnoDB: Unable to allocate memory of size 18446744073709540984.

2013-08-30 03:14:20 7f31e4b96700  InnoDB: Assertion failure in thread 139852267480832 in file ha_innodb.cc line 16865
[30 Aug 2013 5:23] MySQL Verification Team
We need to know the stack trace.  Can you either resolve the stack trace into function names, or run mysqld in gdb ?

gdb /usr/sbin/mysqld
set arg --defaults-file=/path/to/my.cnf --console --gdb
run
........

bt
bt full
[31 Aug 2013 1:55] Josiah Webb
backtrace

Attachment: backtrace.txt (text/plain), 6.14 KiB.

[31 Aug 2013 1:56] Josiah Webb
backtrace full

Attachment: backtrace-full.txt (text/plain), 17.72 KiB.

[31 Aug 2013 1:56] Josiah Webb
Thanks for the response... backtraces attached to this bug!
[31 Aug 2013 7:42] MySQL Verification Team
(gdb) bt
#0  in raise () from /lib64/libc.so.6
#1  in abort () from /lib64/libc.so.6
#2  in ib_logf at ./storage/innobase/handler/ha_innodb.cc:16865
#3  in mem_heap_create_block at ./storage/innobase/mem/mem0mem.cc:360
#4  in mem_heap_add_block at ./storage/innobase/mem/mem0mem.cc:452
#5  in mem_heap_alloc  at ./storage/innobase/include/mem0mem.ic:186
#6  in mem_heap_dup  at ./storage/innobase/mem/mem0mem.cc:125
#7  in trx_undo_rec_copy  at ./storage/innobase/include/trx0rec.ic:111
#8  in trx_undo_get_undo_rec_low  at ./storage/innobase/trx/trx0rec.cc:1429
#9  in trx_undo_get_undo_rec  at ./storage/innobase/trx/trx0rec.cc:1461
#10 in trx_undo_prev_version_build  at ./storage/innobase/trx/trx0rec.cc:1537
#11 in row_vers_old_has_index_entry at ./storage/innobase/row/row0vers.cc:421
#12 in row_purge_poss_sec at ./storage/innobase/row/row0purge.cc:252
#13 in btr_cur_search_to_nth_level  at ./storage/innobase/btr/btr0cur.cc:661
#14 in btr_pcur_open_low  at ./storage/innobase/include/btr0pcur.ic:440
#15 in row_search_index_entry  at ./storage/innobase/row/row0row.cc:815
#16 in row_purge_remove_sec_if_poss_leaf  at ./storage/innobase/row/row0purge.cc:421
#17 in row_purge_remove_sec_if_poss at ./storage/innobase/row/row0purge.cc:482
#18 in row_purge_upd_exist_or_extern_func at ./storage/innobase/row/row0purge.cc:581
#19 in row_purge_record_func  at ./storage/innobase/row/row0purge.cc:818
#20 in row_purge  at ./storage/innobase/row/row0purge.cc:862
#21 in row_purge_step at ./storage/innobase/row/row0purge.cc:942
#22 in que_thr_step  at ./storage/innobase/que/que0que.cc:1105
#23 in que_run_threads_low  at ./storage/innobase/que/que0que.cc:1167
#24 in que_run_threads  at ./storage/innobase/que/que0que.cc:1208
#25 in trx_purge   at ./storage/innobase/trx/trx0purge.cc:1246
#26 in srv_do_purge  at ./storage/innobase/srv/srv0srv.cc:2582
#27 in srv_purge_coordinator_thread  at ./storage/innobase/srv/srv0srv.cc:2759
#28 in start_thread  from /lib64/libpthread.so.0
#29 in clone  from /lib64/libc.so.6

The problem is "len" is absurd here, or undo_rec points to garbage?

trx_undo_rec_copy(
/*==============*/
	const trx_undo_rec_t*	undo_rec,	/*!< in: undo log record */
	mem_heap_t*		heap)		/*!< in: heap where copied */
{
	ulint		len;

	len = mach_read_from_2(undo_rec)
		- ut_align_offset(undo_rec, UNIV_PAGE_SIZE);
	ut_ad(len < UNIV_PAGE_SIZE);
	return((trx_undo_rec_t*) mem_heap_dup(heap, undo_rec, len));

	
Similar crashes once seen in internal Bug #14235384 - SEGV IN UNDO PROCESSING
I guess mysqld-debug or debug build will assert earlier.
[1 Sep 2013 9:47] MySQL Verification Team
Kindly send us the complete mysql error log so we can check previous startups, upgrades, etc.
[4 Sep 2013 15:01] Josiah Webb
We toasted this EC2 instance over the weekend (AWS cluster compute instance are expensive to have sitting around doing nothing). I am trying from scratch again (this was already done 3 times prior w/ the same erroneous results) and will report if i experience the same error. The instance i am creating now is using a more "vanilla" AWS AMI (Bashton CentOS-6.4). 

I'll let you know in the next day or 2 and will be able to provide complete logs for you if it recurs.
[23 Jan 2014 0:36] MySQL Verification Team
Setting "can't repeat" here until we see this again.