← Back to team overview

holland-discuss team mailing list archive

Re: xtrabackup error

 

Hmm. Good catch. I just banged my head on what happened here.  Looks like a
missed merge on our build server - probably user error on my part when I
was pushing the final updated packages out.  I'll have this fixed shortly.

~Andrew


On Wed, Mar 20, 2013 at 4:12 PM, Robert Navarro <rnavarro@xxxxxxxxxxxxxx>wrote:

> I figured out the issue with my local install, it was actually fixed in
> this commit:
>
>
> https://github.com/holland-backup/holland/commit/582f8748c85fa60be4f5e58fd3ee20f1ef9397f6
>
> However it looks like the debian holland-xtrabackup package does not
> contain the actual 1.0.8 code
>
> Taking a look at the holland-xtrabackup_1.0.8-1_all.deb it looks like the
> included source isn't correct. The bug was fixed on February 4, 2013 but
> the included source doesn't include those changes.
>
>
> On Wed, Mar 20, 2013 at 1:23 PM, Andrew Garner <muzazzi@xxxxxxxxx> wrote:
>
>> The holland-xtrabackup plugin only applies compression to streaming
>> backups as of v1.0.8.   However, with non-streaming backups there are a
>> couple options:
>>
>> 1) Use xtrabackup's --compress option.  There is currently not an
>> explicit holland option for this, but you can add arbitrary options in
>> [xtrabackup] -> additional options.  --compress uses 'qpress'/quicklz
>> compression and requires external tools to actually uncompress your files.
>>
>> To enable that in holland the config would look like:
>>
>> /etc/holland/backupsets/xtrabackup.conf:
>> ...
>> [xtrabackup]
>> additional-options = --compress
>>
>> The backup files would end up with '.qp' suffixes and to uncompress you
>> would need one of the tools from: http://www.quicklz.com/
>>
>> With --compress you can't also apply-logs and holland-xtrabackup will
>> automatically skip this step when it detects this case.  To apply logs you
>> have to uncompress with the quicklz tools and then you can go through the
>> normal xtrabackup recovery procedures.
>>
>> 2) holland 1.0.8 allows for arbitrary pre/post commands that can be run
>> against the backup directory:
>>
>> [holland:backup]
>> plugin = xtrabackup
>> ...
>> # replace with your favorite compression command
>> after-backup-command = gzip --fast --recursive ${backupdir}/data/
>>
>> Where '${backupdir}' gets interpolated with the real backup directory by
>> holland.  These are run after the xtrabackup commands complete, including
>> innobackupex --apply-logs.   holland-xtrabackup always stores data under
>> the ./data/ directory in the backup_directory allocated, so to compress the
>> xtrabackup data you always want to reference this as ${backupdir}/data/.
>>
>> The *-command options are documented here:
>> http://docs.hollandbackup.org/config.html#backup-set-configs
>>
>> ~Andrew
>>
>>
>> On Wed, Mar 20, 2013 at 2:34 PM, Robert Navarro <rnavarro@xxxxxxxxxxxxxx>wrote:
>>
>>> Thanks for that information. I've made a few tweaks to the zombie
>>> killing script to ignore this process and things look like they're working
>>> great!
>>>
>>> Related question though, how is compression applied to an xtrabackup
>>> backup?
>>>
>>> Do I have to perform a streaming backup for it to get gzipped?
>>>
>>>
>>> On Tue, Mar 19, 2013 at 10:35 PM, Andrew Garner <muzazzi@xxxxxxxxx>wrote:
>>>
>>>> This " [sh] <defunct>" process is the 'mysql' process forked by the
>>>> innobackupex perl script. The perl script slightly lies here when it says "innobackupex:
>>>> Connection to database server closed" - certainly the connection is closed,
>>>> but the forked shell is never reaped, so that will stay defunct/zombie
>>>> until xtrabackup starts actively using the mysql connection towards the end
>>>> of the backup.
>>>>
>>>> If your zombie killing script is terminating innobackupex with a normal
>>>> signal, this will just terminate the perl script and xtrabackup will
>>>> certainly continue to run.  You probably want to avoid killing anything the
>>>> xtrabackup process chain, but if you do you probably want to send a signal
>>>> to the entire process group rather than just the innobackupex script.
>>>>
>>>> ~Andrew
>>>>
>>>>
>>>>
>>>>
>>>>
>>>>
>>>> On Tue, Mar 19, 2013 at 8:47 PM, Robert Navarro <
>>>> rnavarro@xxxxxxxxxxxxxx> wrote:
>>>>
>>>>> So it looks like the actual innobackupex dies, but the
>>>>> underlying xtrabackup_55 process is still running. Here's the process
>>>>> output right after I start the backup (pre failure)
>>>>>
>>>>> 0:00 SCREEN -S holland
>>>>> 0:00  \_ /bin/bash
>>>>> 0:00      \_ /usr/bin/python /usr/sbin/holland bk
>>>>> 0:00          \_ perl /usr/bin/innobackupex
>>>>> --defaults-file=/var/backups/default/20130319_183505/my.cnf --stream=tar
>>>>> --tmpdir=/var/backups/default/20130319_183505 --slave-info --no-timestamp
>>>>> /var/backups/default/20130319_183505
>>>>> 0:00              \_ [sh] <defunct>
>>>>> 0:00              \_ sh -c xtrabackup_55
>>>>>  --defaults-file="/var/backups/default/20130319_183505/my.cnf"
>>>>>  --defaults-group="mysqld" --backup --suspend-at-end
>>>>> --target-dir=/var/backups/default/20130319_183505 --stream=tar
>>>>> 0:23                  \_ xtrabackup_55
>>>>> --defaults-file=/var/backups/default/20130319_183505/my.cnf
>>>>> --defaults-group=mysqld --backup --suspend-at-end
>>>>> --target-dir=/var/backups/default/20130319_183505 --stream=tar
>>>>>
>>>>> Here's the output post-failure:
>>>>>
>>>>> 0:00 SCREEN -S holland
>>>>> 0:00  \_ /bin/bash
>>>>> 0:00 sh -c xtrabackup_55
>>>>>  --defaults-file="/var/backups/default/20130319_183505/my.cnf"
>>>>>  --defaults-group="mysqld" --backup --suspend-at-end
>>>>> --target-dir=/var/backups/default/20130319_183505 --stream=tar
>>>>> 1:01  \_ xtrabackup_55
>>>>> --defaults-file=/var/backups/default/20130319_183505/my.cnf
>>>>> --defaults-group=mysqld --backup --suspend-at-end
>>>>> --target-dir=/var/backups/default/20130319_183505 --stream=tar
>>>>>
>>>>> Sorry for the bad formatting, might want to paste this into an editor
>>>>> that doesn't line wrap.
>>>>>
>>>>> Here's a pastebin if you prefer that
>>>>> http://pastebin.ca/2336238
>>>>>
>>>>> Another interesting note, it looks like an orphaned shell prompt is
>>>>> opened up. I have some scripts that run on our boxes to kill zombie
>>>>> processes so I wonder if when I kill this zombie it shuts everything down.
>>>>> Is there a reason this zombie process window is opened?
>>>>>
>>>>> On Tue, Mar 19, 2013 at 5:37 PM, Andrew Garner <muzazzi@xxxxxxxxx>wrote:
>>>>>
>>>>>> Hmm.  This looks like innobackupex was terminated with a SIGKILL for
>>>>>> some reason, since the exit status is -9.  Of course any negative exit
>>>>>> status will be due to a signal.
>>>>>>
>>>>>> You are saying that if you disable auto-purge-failures that the
>>>>>> behavior is changing, and innobackupex is actually running in the
>>>>>> background even though holland seems to have failed?
>>>>>>
>>>>>> ~Andrew
>>>>>>
>>>>>>
>>>>>>
>>>>>>
>>>>>> On Tue, Mar 19, 2013 at 7:15 PM, Robert Navarro <
>>>>>> rnavarro@xxxxxxxxxxxxxx> wrote:
>>>>>>
>>>>>>> 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
>>>>>>>
>>>>>>> _______________________________________________
>>>>>>> Mailing list: https://launchpad.net/~holland-discuss
>>>>>>> Post to     : holland-discuss@xxxxxxxxxxxxxxxxxxx
>>>>>>> Unsubscribe : https://launchpad.net/~holland-discuss
>>>>>>> More help   : https://help.launchpad.net/ListHelp
>>>>>>>
>>>>>>>
>>>>>>
>>>>>
>>>>>
>>>>> --
>>>>> Robert Navarro
>>>>> Lead Backend Developer
>>>>> rnavarro@xxxxxxxxxxxxxx
>>>>> www.stitchlabs.com
>>>>>  <http://www.stitchlabs.com/>San Francisco, CA
>>>>>
>>>>
>>>>
>>>
>>>
>>> --
>>> Robert Navarro
>>> Lead Backend Developer
>>> rnavarro@xxxxxxxxxxxxxx
>>> www.stitchlabs.com
>>> <http://www.stitchlabs.com/>San Francisco, CA
>>>
>>
>>
>
>
> --
> Robert Navarro
> Lead Backend Developer
> rnavarro@xxxxxxxxxxxxxx
> <j@xxxxxxxxxxxxxx>
> +1 530.868.6237
> www.stitchlabs.com
> <http://www.stitchlabs.com/>San Francisco, CA
>

References