InnoDB: Cannot allocate 18446744073709540680 bytes of memory after 60 retries over 60 seconds.

[djbur...@gmail.com]

Just tried starting my mysql server (on localhost) this morning, and got the error above. I've put more detail below. I then get Windows' "mysqld.exe has stopped working" message. I've tried starting with innodb_force_recovery=1, but I still get the error.

Any idea what I should be looking for? Note that I can't get into the database so can't run queries...

In the detail below, I note that InnoDB is trying to allocate something like 16.8TB of memory - something that's highly likely to fail given that I've only got 4GB of RAM and 3GB of free disk space. How is this value calculated? I've made no recent config changes or updates to my MySQL installation.

Thanks for any help or pointers!
Dave

In more detail:

2017-02-01T09:03:14.477672Z 0 [ERROR] InnoDB: Cannot allocate 184467440737095406
80 bytes of memory after 60 retries over 60 seconds. OS error: Not enough space
(12). Check if you should increase the swap file or ulimits of your operating sy
stem. Note that on most 32-bit computers the process memory space is limited to
2 GB or 4 GB.
2017-02-01 09:03:14 0x1b98 InnoDB: Assertion failure in thread 7064 in file ut0
ut.cc line 931
InnoDB: Failing assertion: !m_fatal
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
09:03:14 UTC - mysqld got exception 0x80000003 ;
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.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=0
max_threads=151
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 = 68011 K b
ytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x143c3140
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...
13ff7e262 mysqld.exe!my_sigabrt_handler()[my_thr_init.c:449]
140328489 mysqld.exe!raise()[winsig.c:587]
140327380 mysqld.exe!abort()[abort.c:82]
14008f178 mysqld.exe!ut_dbg_assertion_failed()[ut0dbg.cc:67]
14008f44f mysqld.exe!ib::fatal_or_error::~fatal_or_error()[ut0ut.cc:931]
13ffc190f mysqld.exe!ut_allocator<unsigned char>::allocate()[ut0new.h:369]
1400a8aed mysqld.exe!mem_heap_create_block_func()[mem0mem.cc:302]
1400a88c9 mysqld.exe!mem_heap_add_block()[mem0mem.cc:408]
1400a8bd6 mysqld.exe!mem_heap_dup()[mem0mem.cc:59]
1401f543c mysqld.exe!trx_undo_get_undo_rec_low()[trx0rec.cc:2124]
1401f6b8c mysqld.exe!trx_undo_prev_version_build()[trx0rec.cc:2259]
1401d1458 mysqld.exe!row_vers_vc_matches_cluster()[row0vers.cc:704]
1401d0d48 mysqld.exe!row_vers_old_has_index_entry()[row0vers.cc:950]
1401e5b6d mysqld.exe!row_purge_poss_sec()[row0purge.cc:264]
140100ac1 mysqld.exe!btr_cur_search_to_nth_level()[btr0cur.cc:1152]
1401ae87b mysqld.exe!btr_pcur_open_low()[btr0pcur.ic:470]
1401b09bf mysqld.exe!row_search_index_entry()[row0row.cc:1076]
1401e6238 mysqld.exe!row_purge_remove_sec_if_poss_leaf()[row0purge.cc:471]
1401e5fdd mysqld.exe!row_purge_remove_sec_if_poss()[row0purge.cc:587]
1401e6c57 mysqld.exe!row_purge_upd_exist_or_extern_func()[row0purge.cc:710]
1401e5c34 mysqld.exe!row_purge_record_func()[row0purge.cc:988]
1401e53b2 mysqld.exe!row_purge()[row0purge.cc:1034]
1401e6a42 mysqld.exe!row_purge_step()[row0purge.cc:1112]
1401b2d6f mysqld.exe!que_thr_step()[que0que.cc:1056]
1401b24cd mysqld.exe!que_run_threads_low()[que0que.cc:1121]
1401b22c2 mysqld.exe!que_run_threads()[que0que.cc:1160]
13fffcc6f mysqld.exe!srv_task_execute()[srv0srv.cc:2461]
13fffdf1e mysqld.exe!srv_worker_thread()[srv0srv.cc:2508]
76dc59cd kernel32.dll!BaseThreadInitThunk()
76efa561 ntdll.dll!RtlUserThreadStart()

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0):
Connection ID (thread ID): 0
Status: NOT_KILLED

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.

[Axel Schwenke]

On 01.02.2017 10:19, djbur...@gmail.com wrote:
> Just tried starting my mysql server (on localhost) this morning, and got the error above.

> Any idea what I should be looking for?

InnoDB could not allocate memory. The biggest chunk that InnoDB allocates at
startup is the buffer pool (innodb_buffer_pool_size in my.ini)

> In the detail below, I note that InnoDB is trying to allocate something like 16.8TB of
> memory - something that's highly likely to fail given that I've only got
4GB of RAM and
> 3GB of free disk space. How is this value calculated?

That number is bogus. It's 2^64 - 10936. Looks like -10936 was interpreted
as an 64 bit unsigned number. This might be the problem itself. Or not.

What MySQL version is this? Are you upgrading from an old one? Which? What
is in your my.ini?

Keep in mind that some MySQL packages might install a new my.ini. Also that
new MySQL versions can have new defaults. I.e. the buffer pool size default
was increased just recently.

I suggest you set the innodb buffer pools size to some reasonable value in
my.ini; i.e. 1GB. If you had set the size of the InnoDB redo log
(innodb_log_file_size) before, you must retain this setting. Same goes for
the size set in innodb_data_file_path

[djbur...@gmail.com]

Thanks Axel! Comments inline...

On Wednesday, February 1, 2017 at 10:56:54 AM UTC, Axel Schwenke wrote:

> On 01.02.2017 10:19, djb wrote:
> > Just tried starting my mysql server (on localhost) this morning, and got the error above.
> > Any idea what I should be looking for?
>
> InnoDB could not allocate memory. The biggest chunk that InnoDB allocates at
> startup is the buffer pool (innodb_buffer_pool_size in my.ini)
>
> > In the detail below, I note that InnoDB is trying to allocate something like 16.8TB of
> > memory - something that's highly likely to fail given that I've only got
> 4GB of RAM and
> > 3GB of free disk space. How is this value calculated?
>
> That number is bogus. It's 2^64 - 10936. Looks like -10936 was interpreted
> as an 64 bit unsigned number. This might be the problem itself. Or not.
>
> What MySQL version is this? Are you upgrading from an old one? Which? What
> is in your my.ini?

Sorry, had meant to state this:-) 5.7.16, 64-bit, so only 0.0.1 behind the current one. Running on Win7.
The only uncommented settings in my.ini are as follows:
sql_mode=
character-set-server=utf8
collation-server=utf8_unicode_ci
secure-file-priv=
innodb_force_recovery = 1

> Keep in mind that some MySQL packages might install a new my.ini. Also that
> new MySQL versions can have new defaults. I.e. the buffer pool size default
> was increased just recently.
>
> I suggest you set the innodb buffer pools size to some reasonable value in
> my.ini; i.e. 1GB. If you had set the size of the InnoDB redo log
> (innodb_log_file_size) before, you must retain this setting. Same goes for
> the size set in innodb_data_file_path

According to https://dev.mysql.com/doc/refman/5.6/en/innodb-parameters.html#sysvar_innodb_buffer_pool_size , the default on 64-bit is 134217728.
I've now tried setting it to this value explicitly in my.ini (and I know it's being used, as it's reported in the startup:
2017-02-01T11:23:42.362563Z 0 [Note] InnoDB: Initializing buffer pool, total siz
e = 128M, instances = 1, chunk size = 128M

However, I get exactly the same error. Complete output of startup as follows:

mysqld: Could not create or access the registry key needed for the MySQL applica
tion
to log to the Windows EventLog. Run the application with sufficient
privileges once to create the key, add the key manually, or turn off
logging for that application.
2017-02-01T11:23:41.325459Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is
deprecated. Please use --explicit_defaults_for_timestamp server option (see doc
umentation for more details).
2017-02-01T11:23:41.344461Z 0 [Warning] 'NO_AUTO_CREATE_USER' sql mode was not s
et.
2017-02-01T11:23:41.344461Z 0 [Warning] Insecure configuration for --secure-file
-priv: Current value does not restrict location of generated files. Consider set
ting it to a valid, non-empty path.
2017-02-01T11:23:41.354462Z 0 [ERROR] Cannot open Windows EventLog; check privil
eges, or start server with --log_syslog=0
2017-02-01T11:23:41.372464Z 0 [Note] c:\temp\mysql\bin\mysqld (mysqld 5.7.16) st
arting as process 6352 ...
2017-02-01T11:23:41.735500Z 0 [Note] InnoDB: Mutexes and rw_locks use Windows in
terlocked functions
2017-02-01T11:23:41.736500Z 0 [Note] InnoDB: Uses event mutexes
2017-02-01T11:23:41.736500Z 0 [Note] InnoDB: _mm_lfence() and _mm_sfence() are u
sed for memory barrier
2017-02-01T11:23:41.736500Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-02-01T11:23:42.249552Z 0 [Note] InnoDB: Number of pools: 1
2017-02-01T11:23:42.261553Z 0 [Note] InnoDB: Not using CPU crc32 instructions
2017-02-01T11:23:42.362563Z 0 [Note] InnoDB: Initializing buffer pool, total siz
e = 128M, instances = 1, chunk size = 128M
2017-02-01T11:23:42.391566Z 0 [Note] InnoDB: Completed initialization of buffer
pool
2017-02-01T11:23:42.746601Z 0 [Note] InnoDB: Highest supported file format is Ba
rracuda.
2017-02-01T11:23:42.772604Z 0 [Note] InnoDB: Log scan progressed past the checkp
oint lsn 41558753537
2017-02-01T11:23:42.772604Z 0 [Note] InnoDB: Doing recovery: scanned up to log s
equence number 41558753594
2017-02-01T11:23:42.792606Z 0 [Note] InnoDB: Doing recovery: scanned up to log s
equence number 41558753594
2017-02-01T11:23:42.794606Z 0 [Note] InnoDB: Database was not shutdown normally!

2017-02-01T11:23:42.794606Z 0 [Note] InnoDB: Starting crash recovery.
2017-02-01T11:23:49.091236Z 0 [Note] InnoDB: Removed temporary tablespace data f
ile: "ibtmp1"
2017-02-01T11:23:49.093236Z 0 [Note] InnoDB: Creating shared tablespace for temp
orary tables
2017-02-01T11:23:49.095236Z 0 [Note] InnoDB: Setting file '.\ibtmp1' size to 12
MB. Physically writing the file full; Please wait ...
2017-02-01T11:23:49.776304Z 0 [Note] InnoDB: File '.\ibtmp1' size is now 12 MB.
2017-02-01T11:23:49.796306Z 0 [Note] InnoDB: 96 redo rollback segment(s) found.
96 redo rollback segment(s) are active.
2017-02-01T11:23:49.796306Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are
active.
2017-02-01T11:23:49.798306Z 0 [Note] InnoDB: Waiting for purge to start
2017-02-01T11:23:49.848311Z 0 [Note] InnoDB: Waiting for purge to start
2017-02-01T11:23:49.898316Z 0 [Note] InnoDB: page_cleaner: 1000ms intended loop
took 7477ms. The settings might not be optimal. (flushed=0 and evicted=0, during
the time.)
2017-02-01T11:23:49.908317Z 0 [Note] InnoDB: 5.7.16 started; log sequence number
41558753594
2017-02-01T11:23:49.909318Z 0 [Note] InnoDB: Loading buffer pool(s) from c:\temp
\mysql\data\ib_buffer_pool
2017-02-01T11:23:49.941321Z 0 [Note] Plugin 'FEDERATED' is disabled.
2017-02-01T11:23:50.348361Z 0 [Warning] Failed to set up SSL because of the foll
owing SSL library error: SSL context is not usable without certificate and priva
te key
2017-02-01T11:23:50.370364Z 0 [Note] Server hostname (bind-address): '*'; port:
3306
2017-02-01T11:23:50.379365Z 0 [Note] IPv6 is available.
2017-02-01T11:23:50.379365Z 0 [Note] - '::' resolves to '::';
2017-02-01T11:23:50.380365Z 0 [Note] Server socket created on IP: '::'.
2017-02-01T11:23:52.136540Z 0 [Note] Event Scheduler: Loaded 0 events
2017-02-01T11:23:52.136540Z 0 [Note] c:\temp\mysql\bin\mysqld: ready for connect
ions.
Version: '5.7.16' socket: '' port: 3306 MySQL Community Server (GPL)
2017-02-01T11:23:52.327559Z 0 [Note] InnoDB: Buffer pool(s) load completed at 17
0201 11:23:52
2017-02-01T11:24:52.032529Z 0 [ERROR] InnoDB: Cannot allocate 184467440737095406

80 bytes of memory after 60 retries over 60 seconds. OS error: Not enough space
(12). Check if you should increase the swap file or ulimits of your operating sy
stem. Note that on most 32-bit computers the process memory space is limited to
2 GB or 4 GB.

2017-02-01 11:24:52 0x1868 InnoDB: Assertion failure in thread 6248 in file ut0

ut.cc line 931
InnoDB: Failing assertion: !m_fatal
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.

11:24:52 UTC - mysqld got exception 0x80000003 ;

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.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=0
max_threads=151
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 = 68011 K b
ytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x1461b3d0

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...

14078e262 mysqld.exe!my_sigabrt_handler()[my_thr_init.c:449]
140b38489 mysqld.exe!raise()[winsig.c:587]
140b37380 mysqld.exe!abort()[abort.c:82]
14089f178 mysqld.exe!ut_dbg_assertion_failed()[ut0dbg.cc:67]
14089f44f mysqld.exe!ib::fatal_or_error::~fatal_or_error()[ut0ut.cc:931]
1407d190f mysqld.exe!ut_allocator<unsigned char>::allocate()[ut0new.h:369]
1408b8aed mysqld.exe!mem_heap_create_block_func()[mem0mem.cc:302]
1408b88c9 mysqld.exe!mem_heap_add_block()[mem0mem.cc:408]
1408b8bd6 mysqld.exe!mem_heap_dup()[mem0mem.cc:59]
140a0543c mysqld.exe!trx_undo_get_undo_rec_low()[trx0rec.cc:2124]
140a06b8c mysqld.exe!trx_undo_prev_version_build()[trx0rec.cc:2259]
1409e1458 mysqld.exe!row_vers_vc_matches_cluster()[row0vers.cc:704]
1409e0d48 mysqld.exe!row_vers_old_has_index_entry()[row0vers.cc:950]
1409f5b6d mysqld.exe!row_purge_poss_sec()[row0purge.cc:264]
140910ac1 mysqld.exe!btr_cur_search_to_nth_level()[btr0cur.cc:1152]
1409be87b mysqld.exe!btr_pcur_open_low()[btr0pcur.ic:470]
1409c09bf mysqld.exe!row_search_index_entry()[row0row.cc:1076]
1409f6238 mysqld.exe!row_purge_remove_sec_if_poss_leaf()[row0purge.cc:471]
1409f5fdd mysqld.exe!row_purge_remove_sec_if_poss()[row0purge.cc:587]
1409f6c57 mysqld.exe!row_purge_upd_exist_or_extern_func()[row0purge.cc:710]
1409f5c34 mysqld.exe!row_purge_record_func()[row0purge.cc:988]
1409f53b2 mysqld.exe!row_purge()[row0purge.cc:1034]
1409f6a42 mysqld.exe!row_purge_step()[row0purge.cc:1112]
1409c2d6f mysqld.exe!que_thr_step()[que0que.cc:1056]
1409c24cd mysqld.exe!que_run_threads_low()[que0que.cc:1121]
1409c22c2 mysqld.exe!que_run_threads()[que0que.cc:1160]
14080cc6f mysqld.exe!srv_task_execute()[srv0srv.cc:2461]
14080df1e mysqld.exe!srv_worker_thread()[srv0srv.cc:2508]

76dc59cd kernel32.dll!BaseThreadInitThunk()
76efa561 ntdll.dll!RtlUserThreadStart()

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (0):
Connection ID (thread ID): 0
Status: NOT_KILLED

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.

...followed by the Windows message mysqld has stopped working.

Thanks again for looking at this, Axel.
Dave

[Axel Schwenke]

Hi Dave,

On 01.02.2017 12:30, djbur...@gmail.com wrote:

> I've now tried setting it to this value explicitly in my.ini (and I know it's being used, as it's reported in the startup:
> 2017-02-01T11:23:42.362563Z 0 [Note] InnoDB: Initializing buffer pool, total siz
> e = 128M, instances = 1, chunk size = 128M
>
> However, I get exactly the same error. Complete output of startup as follows:

(snip)

That looks serious. Indeed InnoDB starts normally, so this allocation is
nothing related to startup or configuration. In fact this crash happens in
the purge thread (a background thread that purges deleted rows). That can be
either a bug in MySQL or (more likely) data corruption.

I checked bugs.mysql.com, but found no report of similar problems. Hence I
suppose data corruption. I however remember some bugs in that area when
using partitioned InnoDB tables or BLOBs.

If you have no data in that database or if you have a good(!) backup, you
can delete the MySQL datadir, start with a fresh one and restore your data.
Note: if you are unsure if your backup is good, you may keep a copy of the
whole(!) datadir.

Else I suggest you first try latest 5.7. If that still crashes, start MySQL
with innodb_force_recovery=2. You can try even higher recovery levels, but
you need at least 2 to prevent the purge thread to be started. Once MySQL
starts up, use mysqldump to extract your data. Then startup with a fresh
datadir and load your data from the dump.


HTH, XL

[Axel Schwenke]

PS: you might want to check your storage subsystem and memory. While there
are many possible causes for data corruption, those are the most prominent.
If your storage (worn SSD?) causes this, you won't get anywhere when you try
to recover your data.

[djbur...@gmail.com]

Thanks again - I tried innodb_force_recovery=2, and was then able to get into the database & copy everything.

I then moved to 5.7.17. Tried with the same datadir, but still got the error.

Reinitialised with a new datadir, no error - now I just need to import all the data back in again:-)

Still don't really know what was wrong...

Thanks for you assistance anyway!

[The Natural Philosopher]

Sounds like disk corruption.

If the disk has any diagnostics, now might be a good time to use them.

--
Ideas are more powerful than guns. We would not let our enemies have
guns, why should we let them have ideas?

Josef Stalin

[djbur...@gmail.com]

This morning I managed to reimport all the data no problem.

Yes, could well be a disk error. Unfortunately, this machine is a locked down corporate one where I'm not allowed to do anything useful like check a disk for errors:-)

Anyway, thanks again for all the help & comments!

[Peter H. Coffin]

On Fri, 3 Feb 2017 04:15:30 -0800 (PST), djbur...@gmail.com wrote:

> This morning I managed to reimport all the data no problem.
>
> Yes, could well be a disk error. Unfortunately, this machine is a
> locked down corporate one where I'm not allowed to do anything useful
> like check a disk for errors:-)

Well, then. It's not your problem. You tell whomever, or your
management, "Hey, this disk is failing and I have no authority to do
anything about it." And then, when it fails and they lose all their
data, you pull up the email and say "I warned you about this weeks ago.
You did nothing."


--
2. My ventilation ducts will be too small to crawl through.
--Peter Anspach's list of things to do as an Evil Overlord