holland-discuss team mailing list archive

[Robert Navarro <rnavarro@xxxxxxxxxxxxxx>]

Hello,

I'm trying to run Holland with the xtrabackup plugin bug I keep running
into an error.

By default holland just spits out an error and everything dies.

However, if I set auto-purge-failures = no, holland spits out and error and
it dies, however the underlying innobackupex process continues to run
backing up the database as intended.

Here is my backup configuration:

[holland:backup]
plugin = xtrabackup
backups-to-keep = 7
purge-policy = after-backup
estimated-size-factor = 1.0

[xtrabackup]
innobackupex = innobackupex
slave-info = yes
apply-logs = yes
global-defaults = /etc/mysql/my.cnf

[compression]
method             = gzip-rsyncable
inline             = yes
level              = 1

[mysql:client]
defaults-extra-file       = /root/.my.cnf

Here is the log from the backup:

2013-03-19 16:57:37,816 [INFO] Holland 1.0.8 started with pid 3644
2013-03-19 16:57:37,825 [INFO] --- Starting backup run ---
2013-03-19 16:57:37,829 [INFO] Creating backup path
/var/backups/default/20130319_165737
2013-03-19 16:57:37,839 [INFO] * Generating mysql option file:
/var/backups/default/20130319_165737/my.cnf
2013-03-19 16:57:37,839 [INFO]   + Added !include /etc/mysql/my.cnf
2013-03-19 16:57:37,839 [INFO]   + Added !include /root/.my.cnf
2013-03-19 16:57:37,865 [INFO] Estimated Backup Size: 143.73GB
2013-03-19 16:57:37,866 [INFO] Starting backup[default/20130319_165737] via
plugin xtrabackup
2013-03-19 16:57:37,866 [INFO] Executing: /usr/bin/innobackupex
--defaults-file=/var/backups/default/20130319_165737/my.cnf --stream=tar
--tmpdir=/var/backups/default/20130319_165737 --slave-info --no-timestamp
/var/backups/default/20130319_165737
2013-03-19 16:57:37,867 [INFO]   > /dev/null 2 >
/var/backups/default/20130319_165737/xtrabackup.log
2013-03-19 17:00:01,850 [INFO] !! innobackupex exited with failure status
[-9]
2013-03-19 17:00:01,852 [ERROR]     !
2013-03-19 17:00:01,852 [ERROR]     ! InnoDB Backup Utility
v1.5.1-xtrabackup; Copyright 2003, 2009 Innobase Oy
2013-03-19 17:00:01,852 [ERROR]     ! and Percona Ireland Ltd 2009-2012.
 All Rights Reserved.
2013-03-19 17:00:01,852 [ERROR]     !
2013-03-19 17:00:01,852 [ERROR]     ! This software is published under
2013-03-19 17:00:01,853 [ERROR]     ! the GNU GENERAL PUBLIC LICENSE
Version 2, June 1991.
2013-03-19 17:00:01,853 [ERROR]     !
2013-03-19 17:00:01,853 [ERROR]     ! 130319 16:57:38  innobackupex:
Starting mysql with options:
 --defaults-file='/var/backups/default/20130319_165737/my.cnf' --unbuffered
--
2013-03-19 17:00:01,853 [ERROR]     ! 130319 16:57:38  innobackupex:
Connected to database with mysql child process (pid=3647)
2013-03-19 17:00:01,853 [ERROR]     ! 130319 16:57:44  innobackupex:
Connection to database server closed
2013-03-19 17:00:01,854 [ERROR]     ! IMPORTANT: Please check that the
backup run completes successfully.
2013-03-19 17:00:01,854 [ERROR]     !            At the end of a successful
backup run innobackupex
2013-03-19 17:00:01,854 [ERROR]     !            prints "completed OK!".
2013-03-19 17:00:01,854 [ERROR]     !
2013-03-19 17:00:01,854 [ERROR]     ! innobackupex: Using mysql  Ver 14.14
Distrib 5.5.30, for Linux (x86_64) using readline 5.1
2013-03-19 17:00:01,854 [ERROR]     ! innobackupex: Using mysql server
version Copyright (c) 2000, 2013, Oracle and/or its affiliates. All rights
reserved.
2013-03-19 17:00:01,854 [ERROR]     !
2013-03-19 17:00:01,855 [ERROR]     ! innobackupex: Created backup
directory /var/backups/default/20130319_165737
2013-03-19 17:00:01,855 [ERROR]     ! 130319 16:57:44  innobackupex:
Starting mysql with options:
 --defaults-file='/var/backups/default/20130319_165737/my.cnf' --unbuffered
--
2013-03-19 17:00:01,855 [ERROR]     ! 130319 16:57:44  innobackupex:
Connected to database with mysql child process (pid=3682)
2013-03-19 17:00:01,855 [ERROR]     ! 130319 16:57:46  innobackupex:
Connection to database server closed
2013-03-19 17:00:01,855 [ERROR]     !
2013-03-19 17:00:01,855 [ERROR]     ! 130319 16:57:46  innobackupex:
Starting ibbackup with command: xtrabackup_55
 --defaults-file="/var/backups/default/20130319_165737/my.cnf"
 --defaults-group="mysqld" --backup --suspend-at-end
--target-dir=/var/backups/default/20130319_165737 --stream=tar
2013-03-19 17:00:01,856 [ERROR]     ! innobackupex: Waiting for ibbackup
(pid=3689) to suspend
2013-03-19 17:00:01,856 [ERROR]     ! innobackupex: Suspend file
'/var/backups/default/20130319_165737/xtrabackup_suspended'
2013-03-19 17:00:01,856 [ERROR]     !
2013-03-19 17:00:01,856 [ERROR]     ! xtrabackup_55 version 2.0.5 for
Percona Server 5.5.16 Linux (x86_64) (revision id: undefined)
2013-03-19 17:00:01,856 [ERROR]     ! xtrabackup: uses posix_fadvise().
2013-03-19 17:00:01,856 [ERROR]     ! xtrabackup: cd to /var/lib/mysql
2013-03-19 17:00:01,856 [ERROR]     ! xtrabackup: Target instance is
assumed as followings.
2013-03-19 17:00:01,857 [ERROR]     ! xtrabackup:   innodb_data_home_dir =
./
2013-03-19 17:00:01,857 [ERROR]     ! xtrabackup:   innodb_data_file_path =
ibdata1:10M:autoextend
2013-03-19 17:00:01,857 [ERROR]     ! xtrabackup:
innodb_log_group_home_dir = ./
2013-03-19 17:00:01,857 [ERROR]     ! xtrabackup:
innodb_log_files_in_group = 2
2013-03-19 17:00:01,857 [ERROR]     ! xtrabackup:   innodb_log_file_size =
268435456
2013-03-19 17:00:01,858 [ERROR]     ! xtrabackup: using O_DIRECT
2013-03-19 17:00:01,858 [ERROR]     ! 130319 16:57:46  InnoDB: Warning:
allocated tablespace 10, old maximum was 9
2013-03-19 17:00:01,858 [ERROR]     ! >> log scanned up to (1405741884514)
2013-03-19 17:00:01,858 [ERROR]     ! [01] Streaming ./ibdata1
2013-03-19 17:00:01,858 [ERROR]     ! >> log scanned up to (1405741971676)
2013-03-19 17:00:01,858 [ERROR]     ! >> log scanned up to (1405742071652)
2013-03-19 17:00:01,858 [ERROR]     ! >> log scanned up to (1405742142798)
2013-03-19 17:00:01,859 [ERROR]     ! >> log scanned up to (1405742353893)
2013-03-19 17:00:01,859 [ERROR]     ! >> log scanned up to (1405742916821)
2013-03-19 17:00:01,859 [ERROR]     ! >> log scanned up to (1405743051035)
2013-03-19 17:00:01,859 [ERROR]     ! >> log scanned up to (1405743370487)
2013-03-19 17:00:01,859 [ERROR]     ! >> log scanned up to (1405743548944)
2013-03-19 17:00:01,859 [ERROR]     ! >> log scanned up to (1405743698799)
2013-03-19 17:00:01,859 [ERROR]     ! >> log scanned up to (1405743882676)
2013-03-19 17:00:01,860 [ERROR]     ! >> log scanned up to (1405743954700)
2013-03-19 17:00:01,860 [ERROR]     ! >> log scanned up to (1405744054154)
2013-03-19 17:00:01,860 [ERROR]     ! >> log scanned up to (1405744145553)
2013-03-19 17:00:01,860 [ERROR]     ! >> log scanned up to (1405744217159)
2013-03-19 17:00:01,860 [ERROR]     ! >> log scanned up to (1405744288130)
2013-03-19 17:00:01,860 [ERROR]     ! >> log scanned up to (1405744379874)
2013-03-19 17:00:01,860 [ERROR]     ! >> log scanned up to (1405744576745)
2013-03-19 17:00:01,861 [ERROR]     ! >> log scanned up to (1405744644134)
2013-03-19 17:00:01,861 [ERROR]     ! >> log scanned up to (1405744746000)
2013-03-19 17:00:01,861 [ERROR]     ! >> log scanned up to (1405744821309)
2013-03-19 17:00:01,861 [ERROR]     ! >> log scanned up to (1405744916951)
2013-03-19 17:00:01,861 [ERROR]     ! >> log scanned up to (1405745030577)
2013-03-19 17:00:01,861 [ERROR]     ! >> log scanned up to (1405745142619)
2013-03-19 17:00:01,862 [ERROR]     ! >> log scanned up to (1405745223352)
2013-03-19 17:00:01,862 [ERROR]     ! [01]        ...done
2013-03-19 17:00:01,862 [ERROR]     ! [01] Streaming
./<dbname>/gearman_queue.ibd
2013-03-19 17:00:01,862 [ERROR]     ! [01]        ...done
2013-03-19 17:00:01,862 [ERROR]     ! [01] Streaming
./<dbname>/map_contact.ibd
2013-03-19 17:00:01,862 [ERROR]     ! >> log scanned up to (1405745324018)
2013-03-19 17:00:01,863 [ERROR]     ! >> log scanned up to (1405745446764)
2013-03-19 17:00:01,863 [ERROR]     ! [01]        ...done
2013-03-19 17:00:01,863 [ERROR]     ! [01] Streaming
./<dbname>/profile_log.ibd
2013-03-19 17:00:01,863 [ERROR] Backup failed after 2 minutes, 24.02 seconds
2013-03-19 17:00:01,864 [INFO] auto-purge-failures not enabled. Failed
backup not purged.
2013-03-19 17:00:01,864 [ERROR] Backup failed: innobackupex exited with
failure status [-9]
2013-03-19 17:00:01,864 [INFO] Released lock
/etc/holland/backupsets/default.conf
2013-03-19 17:00:01,864 [INFO] --- Ending backup run ---

Any help with this would be most appreciated!

Also, let me know if you need any additional information to debug.

-- 
Robert Navarro
Lead Backend Developer
rnavarro@xxxxxxxxxxxxxx
www.stitchlabs.com
<http://www.stitchlabs.com/>San Francisco, CA