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:
Category:MySQL Server: InnoDB storage engine Severity:S1 (Critical)
Version:5.1.22-rc OS:Solaris
Assigned to: CPU Architecture:Any

[2 Mar 2008 2:18] Justin SB
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:

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.

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:

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.
[2 Mar 2008 5:33] Justin SB
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.
[2 Feb 2009 11:26] Maciek Gabryszak

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.