← Back to team overview

holland-discuss team mailing list archive

Re: xtrabackup error

 

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

Follow ups

References