← Back to team overview

holland-discuss team mailing list archive

Re: xtrabackup error

 

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
>
>

Follow ups

References