[ERROR] : [ genericBackupTaker->takeFullBackupSnapshot: Error: There was an error backing up - The process returned code 9

26 views
Skip to first unread message

Prashant

unread,
Jan 4, 2012, 4:18:14 AM1/4/12
to Xtrabackup Manager
Hi ALL,

I am trying to backup a remote host with XBM. I have configured the
backup volume, host, job, etc. I am able to login into the host which
gets backed up through ssh without any password.

When I run ./xbm backup run "FQHN-RemoteHost" "NightlyBackup", I get
the following in the screen output and the FQHN-RemoteHost.log in the
logs/hosts folder
====================================================================
2012-01-04 13:55:11 [INFO] : [ Initializing Scheduled Backup
"NightlyBackup" (ID #31) for host: FQHN-RemoteHost ... ]
2012-01-04 13:55:11 [INFO] : [ Using Backup Strategy: Rotating sets of
Incremental Backups ]
2012-01-04 13:55:11 [INFO] : [ Using DAY_OF_WEEK as the rotation
method... ]
2012-01-04 13:55:11 [INFO] : [ No snapshots found for this scheduled
backup at all - taking an initial full backup. ]
2012-01-04 13:55:11 [INFO] : [ Attempting to find available ports for
use... ]
2012-01-04 13:55:11 [INFO] : [ Got lock on port 10000. ]
2012-01-04 13:55:11 [INFO] : [ Started Netcat (nc) listener on port
10000 to receive backup tar stream into directory /backup/tds/xbm/FQHN-
RemoteHost/251 ... ]
2012-01-04 13:55:11 [INFO] : [ Running FULL xtrabackup snapshot of /
var/lib/mysql/data via ssh: mysql@FQHN-RemoteHost ... ]
2012-01-04 14:00:11 [INFO] : [ Cleaning up files after failure... ]
2012-01-04 14:00:12 [ERROR] : [ genericBackupTaker-
>takeFullBackupSnapshot: Error: There was an error backing up - The
process returned code 9. The output from the backup is as follows:
InnoDB Backup Utility v1.5.1-xtrabackup; Copyright 2003, 2009 Innobase
Oy
and Percona Inc 2009-2011. All Rights Reserved.
This software is published under
the GNU GENERAL PUBLIC LICENSE Version 2, June 1991.
IMPORTANT: Please check that the backup run completes successfully.
At the end of a successful backup run innobackupex
prints "completed OK!".
innobackupex: Using mysql Ver 14.14 Distrib 5.1.54, for unknown-linux-
gnu (x86_64) using readline 5.1
innobackupex: Using mysql server version Copyright (c) 2000, 2010,
Oracle and/or its affiliates. All rights reserved.

innobackupex: Created backup directory /var/lib/mysql/data
120104 13:55:11 innobackupex: Starting mysql with options: --
password='secure-pw' --user='mybackuper' --unbuffered --
120104 13:55:11 innobackupex: Connected to database with mysql child
process (pid=30762)
120104 13:55:15 innobackupex: Connection to database server closed

120104 13:55:15 innobackupex: Starting ibbackup with command:
xtrabackup --backup --suspend-at-end --log-stream --target-dir=./
innobackupex: Waiting for ibbackup (pid=30773) to suspend
innobackupex: Suspend file '/var/lib/mysql/data/xtrabackup_suspended'

xtrabackup: suspend-at-end is enabled.
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /var/lib/mysql/data
xtrabackup: Target instance is assumed as followings.
xtrabackup: innodb_data_home_dir = ./
xtrabackup: innodb_data_file_path = ibdata1:512M:autoextend
xtrabackup: innodb_log_group_home_dir = ./
xtrabackup: innodb_log_files_in_group = 2
xtrabackup: innodb_log_file_size = 536870912
xtrabackup: use O_DIRECT
120104 13:55:15 InnoDB: Warning: allocated tablespace 785, old
maximum was 9
xtrabackup: Stream mode.
>> log scanned up to (114575146)

120104 13:55:17 innobackupex: Continuing after ibbackup has suspended

innobackupex: Starting to backup InnoDB tables and indexes
innobackupex: from original InnoDB data directory '/var/lib/mysql/
data'
innobackupex: Backing up as tar stream 'ibdata1'
tar4ibd: using O_DIRECT for the input file.
>> log scanned up to (114575146)
>> log scanned up to (114575146)
>> log scanned up to (114575146)
innobackupex: Backing up file '/var/lib/mysql/data/mydb1/
jms_messages.ibd'
innobackupex: Backing up file '/var/lib/mysql/data/mydb1/
jms_roles.ibd'
innobackupex: Backing up file '/var/lib/mysql/data/mydb1/
jms_subscriptions.ibd'
innobackupex: Backing up file '/var/lib/mysql/data/mydb1/
jms_transactions.ibd'
innobackupex: Backing up file '/var/lib/mysql/data/mydb1/
jms_users.ibd'
innobackupex: Backing up files '/var/lib/mysql/data/pptdb/*.ibd' (144
files)
>> log scanned up to (114575146)
120104 13:56:06 innobackupex: Starting mysql with options: --
password='secure-pw' --user='mybackuper' --unbuffered --
120104 13:56:06 innobackupex: Connected to database with mysql child
process (pid=31125)
>> log scanned up to (114575146)
innobackupex:: Not checking slave open temp tables for --safe-slave-
backup because host is not a slave
120104 13:56:12 innobackupex: Connection to database server closed
120104 13:56:12 innobackupex: Starting mysql with options: --
password='secure-pw' --user='mybackuper' --unbuffered --
120104 13:56:12 innobackupex: Connected to database with mysql child
process (pid=31139)
>> log scanned up to (114575146)
120104 13:56:19 innobackupex: Starting to
backup .frm, .MRG, .MYD, .MYI,
innobackupex: .TRG, .TRN, .ARM, .ARZ, .CSM, .CSV and .opt files in
innobackupex: subdirectories of '/var/lib/mysql/data'
innobackupex: Backing up file '/var/lib/mysql/data/mydb1/
jms_transactions.frm'
innobackupex: Backing up file '/var/lib/mysql/data/mydb1/
jms_roles.frm'
innobackupex: Backing up file '/var/lib/mysql/data/mydb1/db.opt'
innobackupex: Backing up file '/var/lib/mysql/data/mydb1/
jms_subscriptions.frm'
innobackupex: Backing up file '/var/lib/mysql/data/mydb1/
jms_users.frm'
innobackupex: Backing up file '/var/lib/mysql/data/mydb1/
jms_messages.frm'
innobackupex: Backing up files '/var/lib/mysql/data/
split_all_india_city/*.
{frm,MYD,MYI,MRG,TRG,TRN,ARM,ARZ,CSM,CSV,opt,par}' (35614 files)
>> log scanned up to (114575146)
>> log scanned up to (114575146)
>> log scanned up to (114575146)
innobackupex: Backing up files '/var/lib/mysql/data/mysql/*.
{frm,MYD,MYI,MRG,TRG,TRN,ARM,ARZ,CSM,CSV,opt,par}' (69 files)
>> log scanned up to (114575146)
innobackupex: Backing up files '/var/lib/mysql/data/pptdb/*.
{frm,MYD,MYI,MRG,TRG,TRN,ARM,ARZ,CSM,CSV,opt,par}' (316 files)
120104 13:59:59 innobackupex: Finished backing
up .frm, .MRG, .MYD, .MYI, .TRG, .TRN, .ARM, .ARZ, .CSV, .CSM and .opt
files

innobackupex: Resuming ibbackup

xtrabackup: The latest check point (for incremental): '114575146'
>> log scanned up to (114575146)
xtrabackup: Transaction log of lsn (114575146) to (114575146) was
copied.
120104 13:59:59 innobackupex: Connection to database server closed
120104 13:59:59 innobackupex: Starting mysql with options: --
password='secure-pw' --user='mybackuper' --unbuffered --
120104 13:59:59 innobackupex: Connected to database with mysql child
process (pid=10903)
innobackupex:: Starting slave SQL thread
innobackupex: Error: mysql child process has died: ERROR 1200 (HY000)
at line 3: The server is not configured as slave; fix in config file
or with CHANGE MASTER TO
while waiting for reply to MySQL request: 'START SLAVE SQL_THREAD;'
at /usr/bin/innobackupex line 336.
]
2012-01-04 14:00:12 [INFO] : [ Released lock on port 10000. ]
Trace:
#0 /home/xbm/xtrabackup-manager/includes/
rotatingBackupTaker.class.php(205): genericBackupTaker-
>takeFullBackupSnapshot(Object(scheduledBackup),
Object(backupSnapshotGroup))
#1 /home/xbm/xtrabackup-manager/includes/
backupSnapshotTaker.class.php(182): rotatingBackupTaker-
>takeScheduledBackupSnapshot(Object(scheduledBackup))
#2 /home/xbm/xtrabackup-manager/includes/cliHandler.class.php(875):
backupSnapshotTaker-
>takeScheduledBackupSnapshot(Object(scheduledBackup))
#3 /home/xbm/xtrabackup-manager/includes/cliHandler.class.php(97):
cliHandler->handleBackupActions(Array)
#4 /home/xbm/xtrabackup-manager/xbm(36): cliHandler-
>handleArguments(Array)
#5 {main}
====================================================================

Prashant

unread,
Jan 4, 2012, 4:24:21 AM1/4/12
to Xtrabackup Manager
The xbm.log is
==========================================================
2012-01-04 13:55:11 [DEBUG] : [ hostGetter->getByName: Sending SQL:
SELECT host_id FROM hosts WHERE hostname='blr-cos-ppt01.digi.com' ]
2012-01-04 13:55:11 [DEBUG] : [ hostGetter->getByName: Query took
7.9870223999023E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackupGetter-
>getByHostnameAndName: Sending SQL: SELECT scheduled_backup_id FROM
scheduled_backups
WHERE host_id=41 AND name='NightlyBackup' ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackupGetter-
>getByHostnameAndName: Query took 3.6954879760742E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=31 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Query took
4.3869018554688E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=31 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Query took
4.1007995605469E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=31 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Query took
4.2915344238281E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=31 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Query took
4.2915344238281E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=31 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Query took
4.1007995605469E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->cleanQueue: Sending SQL:
SELECT queue_ticket_id, pid FROM queue_tickets WHERE
queue_name='scheduledBackup:31' ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->cleanQueue: Query took
0.0002288818359375 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->cleanQueue: Sending SQL:
DELETE FROM queue_tickets WHERE queue_ticket_id=801 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->cleanQueue: Query took
0.0027148723602295 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->getTicketNumber: Sending
SQL: INSERT INTO queue_tickets (queue_ticket_id, queue_name,
entry_time, pid) VALUES (NULL, 'scheduledBackup:31', NOW(), 20108) ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->getTicketNumber: Query
took 0.0025548934936523 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->cleanQueue: Sending SQL:
SELECT queue_ticket_id, pid FROM queue_tickets WHERE
queue_name='hostBackup:41' ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->cleanQueue: Query took
0.00010204315185547 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->getTicketNumber: Sending
SQL: INSERT INTO queue_tickets (queue_ticket_id, queue_name,
entry_time, pid) VALUES (NULL, 'hostBackup:41', NOW(), 20108) ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->getTicketNumber: Query
took 0.0015039443969727 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->cleanQueue: Sending SQL:
SELECT queue_ticket_id, pid FROM queue_tickets WHERE
queue_name='scheduledBackup:31' ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->cleanQueue: Query took
9.9897384643555E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->checkFrontOfQueue:
Sending SQL: SELECT queue_ticket_id FROM queue_tickets WHERE
queue_name='scheduledBackup:31' AND queue_ticket_id=831 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->checkFrontOfQueue: Query
took 9.8943710327148E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->checkFrontOfQueue:
Sending SQL: SELECT queue_ticket_id FROM queue_tickets WHERE
queue_name='scheduledBackup:31' ORDER BY entry_time ASC LIMIT 1 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->checkFrontOfQueue: Query
took 0.00010919570922852 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->cleanQueue: Sending SQL:
SELECT queue_ticket_id, pid FROM queue_tickets WHERE
queue_name='hostBackup:41' ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->cleanQueue: Query took
0.00010013580322266 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->checkFrontOfQueue:
Sending SQL: SELECT queue_ticket_id FROM queue_tickets WHERE
queue_name='hostBackup:41' AND queue_ticket_id=841 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->checkFrontOfQueue: Query
took 9.2029571533203E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->checkFrontOfQueue:
Sending SQL: SELECT queue_ticket_id FROM queue_tickets WHERE
queue_name='hostBackup:41' ORDER BY entry_time ASC LIMIT 1 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->checkFrontOfQueue: Query
took 0.00010204315185547 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->cleanQueue: Sending SQL:
SELECT queue_ticket_id, pid FROM queue_tickets WHERE
queue_name='scheduledBackup:GLOBAL' ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->cleanQueue: Query took
0.00010204315185547 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->getTicketNumber: Sending
SQL: INSERT INTO queue_tickets (queue_ticket_id, queue_name,
entry_time, pid) VALUES (NULL, 'scheduledBackup:GLOBAL', NOW(),
20108) ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->getTicketNumber: Query
took 0.0017471313476562 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->cleanQueue: Sending SQL:
SELECT queue_ticket_id, pid FROM queue_tickets WHERE
queue_name='scheduledBackup:GLOBAL' ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->cleanQueue: Query took
0.00010800361633301 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->checkFrontOfQueue:
Sending SQL: SELECT queue_ticket_id FROM queue_tickets WHERE
queue_name='scheduledBackup:GLOBAL' AND queue_ticket_id=851 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->checkFrontOfQueue: Query
took 9.0837478637695E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->checkFrontOfQueue:
Sending SQL: SELECT queue_ticket_id FROM queue_tickets WHERE
queue_name='scheduledBackup:GLOBAL' ORDER BY entry_time ASC LIMIT 1 ]
2012-01-04 13:55:11 [DEBUG] : [ queueManager->checkFrontOfQueue: Query
took 0.00010418891906738 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=31 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Query took
4.2915344238281E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=31 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Query took
4.4107437133789E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getParameters:
Sending SQL: SELECT bsp.param_name, sbp.param_value FROM
scheduled_backups sb JOIN backup_strategy_params bsp
ON sb.backup_strategy_id = bsp.backup_strategy_id
JOIN scheduled_backup_params sbp
ON sbp.scheduled_backup_id = sb.scheduled_backup_id AND
bsp.backup_strategy_param_id = sbp.backup_strategy_param_id
WHERE
sb.scheduled_backup_id=31 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getParameters: Query
took 4.0054321289062E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup-
>getSnapshotGroupsNewestToOldest: Sending SQL: SELECT DISTINCT
snapshot_group_num FROM backup_snapshots WHERE scheduled_backup_id=31
AND status='COMPLETED' ORDER BY snapshot_group_num DESC ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup-
>getSnapshotGroupsNewestToOldest: Query took 0.00015497207641602 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=31 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Query took
4.2915344238281E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=31 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Query took
4.5061111450195E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=31 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Query took
5.3167343139648E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=31 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Query took
4.2200088500977E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=31 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Query took
4.1961669921875E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=31 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Query took
4.1007995605469E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=31 ]
2012-01-04 13:55:11 [DEBUG] : [ scheduledBackup->getInfo: Query took
7.7009201049805E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ mysqlTypeGetter->getById: Sending SQL:
SELECT mysql_type_id FROM mysql_types WHERE mysql_type_id=1 ]
2012-01-04 13:55:11 [DEBUG] : [ mysqlTypeGetter->getById: Query took
4.0054321289062E-05 ]
2012-01-04 13:55:11 [DEBUG] : [ mysqlType->getInfo: Sending SQL:
SELECT * FROM mysql_types WHERE mysql_type_id=1 ]
2012-01-04 13:55:11 [DEBUG] : [ mysqlType->getInfo: Query took
4.887580871582E-05 ]
2012-01-04 14:00:11 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=31 ]
2012-01-04 14:00:11 [DEBUG] : [ scheduledBackup->getInfo: Query took
8.9883804321289E-05 ]
2012-01-04 14:00:11 [DEBUG] : [ scheduledBackup->getInfo: Sending SQL:
SELECT sb.*, bs.strategy_code, bs.strategy_name FROM scheduled_backups
sb JOIN backup_strategies bs ON
sb.backup_strategy_id=bs.backup_strategy_id WHERE
scheduled_backup_id=31 ]
2012-01-04 14:00:11 [DEBUG] : [ scheduledBackup->getInfo: Query took
4.3869018554688E-05 ]
==========================================================

Prashant

unread,
Jan 4, 2012, 4:32:13 AM1/4/12
to Xtrabackup Manager
Forgot to mention the contents of logs/hosts/FQHN-
RemoteHost.netcat.log. Here it is:
================================
backup-my.cnf
ibdata1
mydb1/1.ibd
mydb1/2.ibd
mydb1/3.ibd
.......
mydb2/a.ibd
mydb2/b.ibd
mydb2/c.ibd
mydb2/d.ibd
....
tar: Read 1024 bytes from -
================================
However, the backup directory is empty

Lachlan Mulcahy

unread,
Jan 4, 2012, 1:00:19 PM1/4/12
to xtrabac...@googlegroups.com
Hi Prashant,

See my reply inline below...

On 04/01/2012, at 1:18 AM, Prashant wrote:

> Hi ALL,
>
> I am trying to backup a remote host with XBM. I have configured the
> backup volume, host, job, etc. I am able to login into the host which
> gets backed up through ssh without any password.
>
> When I run ./xbm backup run "FQHN-RemoteHost" "NightlyBackup", I get
> the following in the screen output and the FQHN-RemoteHost.log in the
> logs/hosts folder
> ====================================================================

<snip>

> 120104 13:59:59 innobackupex: Connected to database with mysql child
> process (pid=10903)
> innobackupex:: Starting slave SQL thread
> innobackupex: Error: mysql child process has died: ERROR 1200 (HY000)
> at line 3: The server is not configured as slave; fix in config file
> or with CHANGE MASTER TO
> while waiting for reply to MySQL request: 'START SLAVE SQL_THREAD;'
> at /usr/bin/innobackupex line 336.
> ]

The error above indicates that the innobackupex script (part of XtraBackup itself) that was running the MySQL backup attempted to send a "START SLAVE SQL_THREAD" command, but then received an error because the system you are backing up is not actually a slave database.

I believe this only occurs in earlier versions of XtraBackup -- can you verify which version of XtraBackup you have installed on that system?

I actually submitted a fix for this very issue that should be included in the XtraBackup 1.6.4 release -- so if you are not running that version, could you please try upgrading?

Let me know how you go.

Best Regards,
Lachlan

Prashant

unread,
Jan 5, 2012, 12:35:07 AM1/5/12
to Xtrabackup Manager
Hi Lachlan,

Upgrading to xtrabackup-1.6.4-314.rhel5.x86_64 resolved the error. I
realized that after I browsed the tickets for xtrabackup

Thanks & Regards
Prashant

Lachlan Mulcahy

unread,
Jan 5, 2012, 12:17:11 PM1/5/12
to xtrabac...@googlegroups.com
Hi Prashant,

On 04/01/2012, at 9:35 PM, Prashant wrote:

> Hi Lachlan,
>
> Upgrading to xtrabackup-1.6.4-314.rhel5.x86_64 resolved the error. I
> realized that after I browsed the tickets for xtrabackup

Great news!

Glad to hear it is working.

Lachlan

Reply all
Reply to author
Forward
0 new messages