| Bug #8612 | InnoDB Hot Backup problem | ||
|---|---|---|---|
| Submitted: | 18 Feb 2005 22:33 | Modified: | 23 Feb 2005 16:11 |
| Reporter: | Keith Larson | Email Updates: | |
| Status: | Not a Bug | Impact on me: | |
| Category: | MySQL Server: InnoDB storage engine | Severity: | S1 (Critical) |
| Version: | 4.0.X | OS: | Linux (fedora core 2) |
| Assigned to: | Heikki Tuuri | CPU Architecture: | Any |
[18 Feb 2005 22:33]
Keith Larson
[18 Feb 2005 22:48]
Keith Larson
PS I am using ibbackup to make hot backups of course to save from doing dumps and slowing or locking DB. File is around 100 Gig. From mysql Ver 12.22 Distrib 4.0.18, for pc-linux (i686) to mysql Ver 12.22 Distrib 4.0.23, for pc-linux (i686)
[19 Feb 2005 9:13]
Heikki Tuuri
Keith, a possible reason is that you have mixed ib_logfiles. Please study these instructions about how to make a backup: http://www.innodb.com/manual.php#backup.uncompressed http://www.innodb.com/manual.php#restore Please post the complete, unedited, output from the whole backup/restore run: ibbackup ... ibbackup --apply-log ... mysqld and also ls -l from the relevant directories. Regards, Heikki
[22 Feb 2005 14:36]
Keith Larson
OK so here is the process. I have run and I get mysql up but no data. ibbackupA01515 /etc/my.cnf /home/keith/my_backup.cnf > /home/keith/ibbackup.log InnoDB Hot Backup version 2.0.0; Copyright 2003 Innobase Oy License A01515 is granted to "Brady Brown" <brady@flatirontek.com> (--apply-log works in any computer regardless of the hostname) Licensed for use in a computer whose hostname is 'd1' Type ibbackup --license for detailed license terms, --help for help Contents of /etc/my.cnf: innodb_data_home_dir got value /var/lib/mysql innodb_data_file_path got value ibdata1:100G; datadir got value /var/lib/mysql innodb_log_group_home_dir got value /var/lib/mysql innodb_log_files_in_group got value 2 innodb_log_file_size got value 262144000 Contents of /home/keith/my_backup.cnf: innodb_data_home_dir got value /mnt/d2 innodb_data_file_path got value ibdata1:100G; datadir got value /mnt/d2 innodb_log_group_home_dir got value /mnt/d2 innodb_log_files_in_group got value 2 innodb_log_file_size got value 262144000 ibbackup: Found checkpoint at lsn 273 1468746636 ibbackup: Starting log scan from lsn 273 1468746240 050221 11:51:12 ibbackup: Copying log... 050221 11:51:12 ibbackup: Log copied, lsn 273 1468746872 ibbackup: We wait 10 seconds before starting copying the data files... 050221 11:51:22 ibbackup: Copying /var/lib/mysql/ibdata1 050221 11:58:30 ibbackup: Switching to log file 1, lsn 273 1607739392 050221 12:54:51 ibbackup: Switching to log file 0, lsn 273 1869881344 050221 14:07:30 ibbackup: Switching to log file 1, lsn 273 2132023296 050221 15:58:00 ibbackup: Switching to log file 0, lsn 273 2394165248 050221 16:16:12 ibbackup: Switching to log file 1, lsn 273 2656307200 050221 17:23:40 ibbackup: Switching to log file 0, lsn 273 2918449152 050221 17:59:37 ibbackup: Switching to log file 1, lsn 273 3180591104 050221 18:09:31 ibbackup: Switching to log file 0, lsn 273 3442733056 050221 18:21:17 ibbackup: Switching to log file 1, lsn 273 3704875008 050221 18:31:02 ibbackup: Switching to log file 0, lsn 273 3967016960 050221 19:56:43 ibbackup: Switching to log file 1, lsn 273 4229158912 050221 20:01:00 ibbackup: Switching to log file 0, lsn 274 196333568 050221 20:08:13 ibbackup: Switching to log file 1, lsn 274 458475520 050221 20:17:14 ibbackup: Switching to log file 0, lsn 274 720617472 ibbackup: A copied database page was modified at 273 1837316012 ibbackup: Scanned log up to lsn 274 822285086 ibbackup: Was able to parse the log up to lsn 274 822285086 ibbackup: Maximum page number for a log record 611144 050221 20:20:05 ibbackup: Full backup completed! #################### RESTORE ######################## ibbackupA01515 --apply-log my_backup.cnf > ibapplylog.log & # It ran and died. So I checked and then tried to run it again. # ll total 109039436 -rwxrwxrwx 1 mysql mysql 97701 Feb 22 08:19 d2.metasurvey.com.err -rw-rw---- 1 mysql mysql 4 Feb 22 08:19 d2.metasurvey.com.pid -rwxrwxrwx 1 mysql mysql 4 Feb 19 14:36 d2-relay-bin.001 -rwxrwxrwx 1 mysql mysql 4 Feb 19 17:40 d2-relay-bin.002 -rwxrwxrwx 1 mysql mysql 4 Feb 19 18:56 d2-relay-bin.003 -rw-rw---- 1 mysql mysql 4 Feb 22 08:19 d2-relay-bin.004 -rwxrwxrwx 1 mysql mysql 76 Feb 22 08:19 d2-relay-bin.index -rwxrwxrwx 1 root root 3648506880 Feb 21 20:19 ibbackup_logfile -rwxrwxrwx 1 root root 107374182400 Feb 22 08:19 ibdata1 -rwxrwxrwx 1 mysql mysql 262144000 Feb 22 08:19 ib_logfile0 -rwxrwxrwx 1 mysql mysql 262144000 Feb 22 08:19 ib_logfile1 -rwxrwxrwx 1 mysql mysql 18 Feb 22 08:19 master.info drwxrwxrwx 2 mysql mysql 4096 Feb 21 14:01 mysql -rwxrwxrwx 1 root root 92160 Feb 19 17:39 mysql_orig_tables.tar srwxrwxrwx 1 mysql mysql 0 Feb 22 08:19 mysql.sock -rwxrwxrwx 1 root root 92160 Feb 21 10:03 mysql_tables.tar -rwxrwxrwx 1 mysql mysql 24 Feb 22 08:19 relay-log.info drwxrwxrwx 2 mysql mysql 4096 Feb 11 12:42 test [root@d1 keith]# tail ibapplylog.log InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Starting an apply batch of log records to the database... InnoDB: Progress in percents: 0 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 InnoDB: Cannot create /mnt/d2/ib_logfile0. Check that the file does not exist yet. ]# ibbackupA01515 --apply-log my_backup.cnf > ibapplylog.log & [1] 5423 # InnoDB: Doing recovery: scanned up to log sequence number 273 1473989120 InnoDB: Doing recovery: scanned up to log sequence number 273 1479232000 InnoDB: Doing recovery: scanned up to log sequence number 273 1484474880 InnoDB: Doing recovery: scanned up to log sequence number 273 1489717760 InnoDB: Doing recovery: scanned up to log sequence number 273 1494960640 InnoDB: Doing recovery: scanned up to log sequence number 273 1500203520 050222 8:32:36InnoDB: Assertion failure in thread 1073773408 in file ../include/page0page.ic line 482 InnoDB: Failing assertion: offs < UNIV_PAGE_SIZE InnoDB: We intentionally generate a memory trap. InnoDB: Send a detailed bug report to mysql@lists.mysql.com. [1]+ Segmentation fault ibbackupA01515 --apply-log my_backup.cnf >ibapplylog.log Thanks for any and all help.
[22 Feb 2005 14:45]
Heikki Tuuri
Keith, ibbackup prints some of its output to stderr. That output is missing from the printouts. Please repeat the test and let ibbackup print everything to the console, and send the complete printout. Regards, Heikki
[22 Feb 2005 15:21]
Marko Mäkelä
Keith, in order to redirect both stdout and stderr to a file, you can do as follows in Bourne style shells: ibbackupA01515 /etc/my.cnf /home/keith/my_backup.cnf > /home/keith/ibbackup.log 2>&1 Note the "2>&1" at the end of the command. In csh-style shells, the syntax is different, maybe ">&" instead of ">". Marko
[23 Feb 2005 3:36]
Keith Larson
Hey guys. 1st thanks again for the help. So I tried to make this run faster by doing a compress/uncompress as well. I made a URL of the logs. Easier to see and post compare to the textbox. http://65.17.241.60/logs/ ibbackupA01515 --compress /etc/my.cnf /home/keith/my_backup.cnf &> /home/keith/ibbackup.log http://65.17.241.60/logs/ibbackup.log ibbackupA01515 --apply-log --uncompress my_backup.cnf &> ibapplylog.log http://65.17.241.60/logs/ibapplylog.log # ll total 111976668 -rw-rw---- 1 mysql mysql 1836 Feb 22 21:08 d2.metasurvey.com.err -rw-rw---- 1 mysql mysql 5 Feb 22 21:08 d2.metasurvey.com.pid -rw-rw---- 1 mysql mysql 4 Feb 19 14:36 d2-relay-bin.001 -rw-rw---- 1 mysql mysql 4 Feb 19 17:40 d2-relay-bin.002 -rw-rw---- 1 mysql mysql 4 Feb 19 18:56 d2-relay-bin.003 -rw-rw---- 1 mysql mysql 4 Feb 22 08:19 d2-relay-bin.004 -rw-rw---- 1 mysql mysql 4 Feb 22 21:08 d2-relay-bin.005 -rw-rw---- 1 mysql mysql 95 Feb 22 21:08 d2-relay-bin.index -rw-rw---- 1 mysql mysql 2192706048 Feb 22 13:31 ibbackup_logfile -rw-rw---- 1 mysql mysql 107374182400 Feb 22 21:08 ibdata1 -rw-rw---- 1 mysql mysql 4460439673 Feb 22 13:31 ibdata1.ibz -rw-rw---- 1 mysql mysql 262144000 Feb 22 21:08 ib_logfile0 -rw-rw---- 1 mysql mysql 262144000 Feb 22 20:25 ib_logfile1 -rw-rw---- 1 mysql mysql 18 Feb 22 21:08 master.info drwx--x--x 2 mysql mysql 4096 Feb 18 11:09 mysql srwxrwxrwx 1 mysql mysql 0 Feb 22 21:08 mysql.sock -rw-rw---- 1 mysql mysql 24 Feb 22 21:08 relay-log.info drw-rw---- 2 mysql mysql 4096 Feb 11 12:42 test # mysql -u root -p Enter password: Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 1 to server version: 4.0.23-standard Type 'help;' or '\h' for help. Type '\c' to clear the buffer. mysql> SHOW DATABASES; +----------+ | Database | +----------+ | mysql | | test | +----------+ 2 rows in set (0.00 sec) Still no data ?
[23 Feb 2005 4:31]
Keith Larson
I forgot to add the mysql err data : 050222 21:08:01 mysqld started 050222 21:08:01 Warning: Asked for 196608 thread stack, but got 126976 050222 21:08:01 InnoDB: Started /usr/sbin/mysqld: ready for connections. Version: '4.0.23-standard' socket: '/var/lib/mysql/mysql.sock' port: 3306 Official MySQL RPM InnoDB started but no databases mysql> SHOW DATABASES; +----------+ | Database | +----------+ | mysql | | test | +----------+ 2 rows in set (0.00 sec) mysql>
[23 Feb 2005 15:54]
Heikki Tuuri
Keith, you have to back up also the .frm files of the tables. MySQL needs them to see the tables. The ibbackup and ibbackup --apply-log runs look healthy. If you have relatively quiet time in the mysqld server, you can also use: http://www.innodb.com/manual.php#innobackup That Perl script backs up also the .frm files. Regards, Heikki
[23 Feb 2005 16:06]
Keith Larson
Hello, Oh I do back those up as well. But to be safe I just did this : #cd /var/lib/mysql/mysql #tar -cf mysql_frm.tar . #mv mysql_frm.tar /mnt/d2/ # tar -vxf mysql_frm.tar ./ ./db.frm ./db.MYI ./db.MYD ./host.frm ./host.MYI ./host.MYD ./user.frm ./user.MYI ./user.MYD ./func.frm ./func.MYI ./func.MYD ./tables_priv.frm ./tables_priv.MYI ./tables_priv.MYD ./columns_priv.frm ./columns_priv.MYI ./columns_priv.MYD # /etc/rc.d/init.d/mysql start # mysql -u root -p Enter password: Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 1 to server version: 4.0.23-standard Type 'help;' or '\h' for help. Type '\c' to clear the buffer. mysql> SHOW DATABASES; +----------+ | Database | +----------+ | mysql | | test | +----------+ 2 rows in set (0.00 sec) mysql> Aborted Any ideas?
[23 Feb 2005 16:11]
Heikki Tuuri
Keith, your listing shows the MySQL system tables in the /mysql database directory. But also InnoDB type tables have their .frm files. You should back up them, too. Regards, Heikki
[23 Feb 2005 23:50]
Keith Larson
AAAAHHH !! That was it . Never said all the brain cells were working over here. :) Thanks a bunch
[23 Feb 2005 23:56]
Keith Larson
So can I ask one more quick question that relates to this DB.
How DO I know the values for :
-> MASTER_LOG_FILE='recorded_log_file_name',
-> MASTER_LOG_POS=recorded_log_position;
in regards to :
mysql> CHANGE MASTER TO
-> MASTER_HOST='master_host_name',
-> MASTER_USER='replication_user_name',
-> MASTER_PASSWORD='replication_password',
-> MASTER_LOG_FILE='recorded_log_file_name',
-> MASTER_LOG_POS=recorded_log_position;
Which bin do you call ? and what is the position ?
[23 Feb 2005 23:58]
Keith Larson
Is it safe to use this :
mysql> SHOW MASTER STATUS
-> ;
+---------------+-----------+--------------+------------------+
| File | Position | Binlog_do_db | Binlog_ignore_db |
+---------------+-----------+--------------+------------------+
| mysql-bin.004 | 207395007 | | |
+---------------+-----------+--------------+------------------+
1 row in set (0.02 sec)
or is that invalid values.
I relalized I might have just answered my post
[24 Feb 2005 0:23]
Keith Larson
Skip the last posts I got it Edit the my.cnf file of the new slave so that you put skip-slave-start to the [mysqld] section.
