MySQL Bugs: #34979: Signal 11 when trying to use ZFS Snapshot

Bug #34979	Signal 11 when trying to use ZFS Snapshot
Submitted:	2 Mar 2008 2:18	Modified:	2 Mar 2008 5:33
Reporter:	Justin SB	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: InnoDB storage engine	Severity:	S1 (Critical)
Version:	5.1.22-rc	OS:	Solaris
Assigned to:		CPU Architecture:	Any

Description:
I'm trying to mount a snapshot of a ZFS snapshot, on a different server, running 5.1.22-rc. This is running on Solaris 10 x64.

The snapshot technique essentially issues a FLUSH TABLES WITH READ LOCK, then snapshots the ZFS filesystem containing the MySQL data. The code to do is here:
http://blogs.digitar.com/jjww/?itemid=56

This works with the snapshot from a third server. However, when I take the snapshot from the server in question, I get a signal 11 when I try to start mysql.

How can I proceed?

Here are some system details:
# uname -a
SunOS unknown 5.10 Generic_120012-14 i86pc i386 i86pc

# bin/mysqld --version
bin/mysqld Ver 5.1.22-rc for pc-solaris2.10 on i386 (MySQL Community Server (GPL))

MySql is installed from the Solaris 10 tar package mysql-5.1.22-rc-solaris10-x86_64

When I try to start mysqld, the following is sent to the error log:

InnoDB: Log scan progressed past the checkpoint lsn 2 1749088302
080301 18:02:16 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...
InnoDB: Doing recovery: scanned up to log sequence number 2 1749167442
080301 18:02:19 - mysqld got signal 11;
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=2093056
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 = 619255 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Running 5.1.23 under Sun Studio 12, I can see what appears to be the same crash. Here I get a stack trace, which shows:
page_cur_insert_rec_low
page_cur_parse_insert_rec
recv_parse_or_apply_log_rec_body
recv_recover_page
buf_page_io_complete
buf_read_page_low
buf_read_page
buf_page_get_gen
ibuf_data_init_for_space
fil_ibuf_init_at_db_start
ibuf_init_at_db_start
dict_boot
innobase_start_or_create_for_mysql
innobase_init
ha_initialize_handlerton
plugin_initialize
plugin_init
init_server_components
main

How to repeat:
Difficult to reproduce without the snapshot in question... However, the stack trace above should hopefully be a big help to the developer.

Actually, this was an error I made - I didn't bring down the ibdata1 file, and possibly some other files also weren't correctly in place.

Although crashing with a signal 11 is probably slightly over the top,  once I had a consistent copy of all the files everything was fine.

I hope this helps others encountering the same problem.

Hello.

uname -a
SunOS 5.10 Generic_138889-02 i86pc i386 i86pc
+ mysql 5.1.30-GA

when I take the snapshot from anothe mahine in log view:

090202 12:04:03 [Note] Event Scheduler: Killing the scheduler thread, thread id 1
090202 12:04:03 [Note] Event Scheduler: Waiting for the scheduler thread to reply
090202 12:04:03 [Note] Event Scheduler: Stopped
090202 12:04:03 [Note] Event Scheduler: Purging the queue. 1 events
090202 12:07:38 mysqld_safe Starting mysqld daemon with databases from /export/sql
InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
090202 12:07:41  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...
InnoDB: Transaction 0 279239639 was in the XA prepared state.
InnoDB: 1 transaction(s) which must be rolled back or cleaned up
InnoDB: in total 0 row operations to undo
InnoDB: Trx id counter is 0 279240448
InnoDB: Last MySQL binlog file position 0 162839326, file name /export/home/sql/log/master-szukaj-bin.000003
InnoDB: Starting in background the rollback of uncommitted transactions
090202 12:07:42  InnoDB: Rollback of non-prepared transactions completed
090202 12:07:42  InnoDB: Started; log sequence number 10 3298493006
090202 12:07:42  InnoDB: Starting recovery for XA transactions...
090202 12:07:42  InnoDB: Transaction 0 279239639 in prepared state after recovery
090202 12:07:42  InnoDB: Transaction contains changes to 1 rows
090202 12:07:42  InnoDB: 1 transactions in prepared state after recovery
090202 12:07:42 [Note] Found 1 prepared transaction(s) in InnoDB
090202 12:07:42 [Warning] Found 1 prepared XA transactions
090202 12:07:42 [Note] Event Scheduler: Loaded 1 event
090202 12:07:42 [Note] /opt/mysql/mysql/bin/mysqld: ready for connections.
Version: '5.1.30-log'  socket: '/tmp/mysql.sock'  port: 3306  MySQL Community Server (GPL)
090202 12:07:42 [Note] Event Scheduler: scheduler thread started with id 1

I can't change data in innodb tables.
I can't shutdown this database.
I must kill -9 processes but when I try start and view this error again.