Bug #27487 pthread_create failure leads to innodb tablespaces unusable
Submitted: 28 Mar 2007 7:26 Modified: 28 Mar 2007 12:29
Reporter: Shane Bester (Platinum Quality Contributor) Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.1.18, 5.0 OS:Linux (linux)
Assigned to: Assigned Account CPU Architecture:Any
Tags: assertion, innodb, pthread_create

[28 Mar 2007 7:26] Shane Bester
Description:
When specifying a huge stack size using ulimit, mysql (and any other processes) can often fail because pthread_create returns errno 12.

The problem in some cases is innodb dies during initializing, and upon restarting, cannot access the newly created tablespace.

For example, on a 32-bit machine with 2GB of ram, do this:

> ulimit -s 512000

Now, start mysqld_safe and it would probably fail, with this:

070328 09:00:02  mysqld started
InnoDB: The first specified data file ./ibdata1 did not exist:
InnoDB: a new database to be created!
070328  9:00:02  InnoDB: Setting file ./ibdata1 size to 10 MB
InnoDB: Database physically writes the file full: wait...
070328  9:00:02  InnoDB: Log file ./ib_logfile0 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile0 size to 5 MB
InnoDB: Database physically writes the file full: wait...
070328  9:00:02  InnoDB: Log file ./ib_logfile1 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile1 size to 5 MB
InnoDB: Database physically writes the file full: wait...
InnoDB: Error: pthread_create returned 12
070328 09:00:03  mysqld ended

If you restart the mysqld_safe, then innodb complains:

070328 09:00:08  mysqld started
070328  9:00:08  InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
070328  9:00:08  InnoDB: Starting log scan based on checkpoint at
InnoDB: log sequence number 0 8204.
InnoDB: Doing recovery: scanned up to log sequence number 0 8204
InnoDB: Page directory corruption: infimum not pointed to
070328  9:00:08  InnoDB: Page dump in ascii and hex (16384 bytes):
 len 16384; hex 00000 <cut all zeros>

                     ;InnoDB: End of page dump
070328  9:00:08  InnoDB: Page checksum 1575996416, prior-to-4.0.14-form checksum 1371122432
InnoDB: stored checksum 0, prior-to-4.0.14-form stored checksum 0
InnoDB: Page lsn 0 0, low 4 bytes of lsn at page end 0
InnoDB: Page number (if stored to page already) 0,
InnoDB: space id (if created with >= MySQL-4.1.1 and stored already) 0
InnoDB: Page may be a freshly allocated page
InnoDB: Page directory corruption: supremum not pointed to
070328  9:00:08  InnoDB: Page dump in ascii and hex (16384 bytes):
 len 16384; hex 000 <cut all zeros>

                      ;InnoDB: End of page dump
070328  9:00:08  InnoDB: Page checksum 1575996416, prior-to-4.0.14-form checksum 1371122432
InnoDB: stored checksum 0, prior-to-4.0.14-form stored checksum 0
InnoDB: Page lsn 0 0, low 4 bytes of lsn at page end 0
InnoDB: Page number (if stored to page already) 0,
InnoDB: space id (if created with >= MySQL-4.1.1 and stored already) 0
InnoDB: Page may be a freshly allocated page
070328  9:00:08InnoDB: Error: trying to access a stray pointer 0xc23ff8
InnoDB: buf pool start is at 0x80c14000, end at 0x81414000
InnoDB: Probable reason is database corruption or memory
InnoDB: corruption. If this happens in an InnoDB database recovery, see
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-recovery.html
InnoDB: how to force recovery.
070328  9:00:08  InnoDB: Assertion failure in thread 2694985408 in file ../../../storage/innobase/include/buf0buf.ic line 266
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.1/en/forcing-recovery.html
InnoDB: about forcing recovery.
070328  9:00:08 - 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=0
read_buffer_size=131072
max_used_connections=0
max_threads=151
threads_connected=0
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 329405 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd: 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...
Cannot determine thread, fp=0xbfff637c, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
0x81f803c handle_segfault + 796
0xffffe410 _end + -142244384
0xa0a4cb75 _end + -1742049979
0x8424f01 page_cur_search_with_match + 2097
0x84847e5 btr_cur_search_to_nth_level + 1589
0x8485875 btr_pcur_open_on_user_rec + 101
0x84a6d08 dict_load_indexes + 632
0x84a7b27 dict_load_sys_table + 103
0x8497455 dict_boot + 2901
0x845477c innobase_start_or_create_for_mysql + 6220
0x84015b9 _Z13innobase_initPv + 1161
0x830e3e6 _Z24ha_initialize_handlertonP13st_plugin_int + 390
0x83d03d7 _Z11plugin_initi + 791
0x81f6c9c _Z22init_server_componentsv + 364
0x81f92e5 main + 1381
0xa0a38e80 _end + -1742131120
0x810a8c1 _start + 33
New value of fp=(nil) failed sanity check, terminating stack trace!
Please read http://dev.mysql.com/doc/mysql/en/using-stack-trace.html and follow instructions on how to resolve the stack trace. Resolved
stack trace is much more helpful in diagnosing the problem, so please do 
resolve it
The manual page at http://www.mysql.com/doc/en/Crashing.html contains
information that should help you find out what is causing the crash.
070328 09:00:08  mysqld ended

How to repeat:
ulimit -s 512000  <or higher!>
./bin/mysqld_safe &

<dies>

./bin/mysqld_safe &

<dies>

Suggested fix:
I doubt this is a mysql bug - but documenting it seemed like the best thing to do, since we've seen it a few times.

Use lower ulimit -s setting, or leave it unlimited?
Can innodb handle the failure better maybe?
[28 Mar 2007 7:29] Shane Bester
full error log

Attachment: 5.1.18bk_resolved.err (application/octet-stream, text), 101.13 KiB.

[28 Mar 2007 12:29] Heikki Tuuri
Shane,

it is a general problem that InnoDB will create a broken installation if it fails during the initial creation of ibdata1 and ib_logfiles.

This is a duplicate of:

http://bugs.mysql.com/bug.php?id=16533

Regards,

Heikki
[29 Mar 2007 20:25] Shane Bester
fyi: http://sources.redhat.com/bugzilla/show_bug.cgi?id=386
[29 Jun 2007 9:45] Shane Bester
The large stack size causing error 12 with very few threads has really been occurring in some windows builds.  See bug #20815 for a full analysis.