MySQL Bugs: #47862: InnoDB logging method makes it difficult to read

Bug #47862	InnoDB logging method makes it difficult to read
Submitted:	6 Oct 2009 13:06
Reporter:	Roger David Nay	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S4 (Feature request)
Version:	5.0+	OS:	Any
Assigned to:	Assigned Account	CPU Architecture:	Any

Description:
If the server is restarted too quickly mysql can not get the memory allocation it needs and gives an error. The reason is not clear, and gets lost in the comments that are split up making them hard to read. Also, some rows have timestamps some don't and that is unclear why.

091004 20:32:54 mysqld restarted
091004 20:32:54 InnoDB: Error: cannot allocate 12582928384 bytes of
InnoDB: memory with malloc! Total allocated memory
InnoDB: by InnoDB 45007312 bytes. Operating system errno: 12
InnoDB: Check if you should increase the swap file or
InnoDB: ulimits of your operating system.
InnoDB: On FreeBSD check you have compiled the OS with
InnoDB: a big enough maximum process size.
InnoDB: Note that in most 32-bit computers the process
InnoDB: memory space is limited to 2 GB or 4 GB.
InnoDB: We keep retrying the allocation for 60 seconds...
InnoDB: Log scan progressed past the checkpoint lsn 1058 3043602399
091004 20:32:59 InnoDB: Database was not shut down normally!

How to repeat:
Shut down and restart the server before it has a chance to release all of the memory.

Suggested fix:
Don't cut up the lines mid sentence. Add a "Recovered, managed to allocate..." message like below when the memory has been allocated. Something like:

091004 20:32:54 mysqld restarted
091004 20:32:54 InnoDB: Error: cannot allocate 12582928384 bytes of
memory with malloc! Total allocated memory by InnoDB 45007312 bytes. Operating system errno: 12
InnoDB: Check if you should increase the swap file or ulimits of your operating system. On FreeBSD check you have compiled the OS with a big enough maximum process size. Note that in most 32-bit computers the process memory space is limited to 2 GB or 4 GB.
InnoDB: We keep retrying the allocation for 60 seconds...
InnoDB: Recovered, managed to allocate 12582928384 bytes of memory, Continuing...
InnoDB: Log scan progressed past the checkpoint lsn 1058 3043602399
091004 20:32:59 InnoDB: Database was not shut down normally!

Informational messages about FreeBSD and 32 bit computers could possibly be removed as well. In this startup neither FreeBSD or a 32 bit operating system was in use.