innobackupex gets mysql access denied near the *end* of the backup process

Hi all,

I’m using innobackupex this way :

innobackupex --user=backups --password=xxxxxxxx --slave-info --safe-slave-backup --stream=tar /var/lib/mysql/tmp4backup | bzip2 | ssh somehost “cat > backupfile.tar.bz2”

Everything starts fine and goes on for 15 minutes, almost until the end :

InnoDB Backup Utility v1.5.1-xtrabackup; Copyright 2003, 2009 Innobase Oyand Percona Inc 2009-2012. All Rights Reserved.This software is published underthe GNU GENERAL PUBLIC LICENSE Version 2, June 1991.120215 13:00:21 innobackupex: Starting mysql with options: --password=xxxxxxxx --user=‘backups’ --unbuffered --120215 13:00:21 innobackupex: Connected to database with mysql child process (pid=2265)120215 13:00:27 innobackupex: Connection to database server closedIMPORTANT: 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.41, for debian-linux-gnu (x86_64) using readline 6.1innobackupex: Using mysql server version Copyright 2000-2008 MySQL AB, 2008 Sun Microsystems, Inc.Warning: option ‘innodb_autoextend_increment’: unsigned value 52428800 adjusted to 1000innobackupex: Created backup directory /var/lib/mysql/tmp4backup120215 13:00:27 innobackupex: Starting mysql with options: --password=xxxxxxxx --user=‘backups’ --unbuffered --120215 13:00:27 innobackupex: Connected to database with mysql child process (pid=2318)120215 13:00:29 innobackupex: Connection to database server closed120215 13:00:29 innobackupex: Starting ibbackup with command: xtrabackup_51 --backup --suspend-at-end --log-stream --target-dir=/var/lib/mysql/tmpinnobackupex: Waiting for ibbackup (pid=2326) to suspendinnobackupex: Suspend file '/var/lib/mysql/tmp/xtrabackup_suspended’Warning: option ‘innodb_autoextend_increment’: unsigned value 52428800 adjusted to 1000xtrabackup: suspend-at-end is enabled.xtrabackup: uses posix_fadvise().xtrabackup: cd to /var/lib/mysqlxtrabackup: Target instance is assumed as followings.xtrabackup: innodb_data_home_dir = ./xtrabackup: innodb_data_file_path = ibdata1:10M:autoextendxtrabackup: innodb_log_group_home_dir = ./xtrabackup: innodb_log_files_in_group = 2xtrabackup: innodb_log_file_size = 268435456xtrabackup: Stream mode.>> log scanned up to (190 953622505)120215 13:00:31 innobackupex: Continuing after ibbackup has suspendedinnobackupex: Starting to backup InnoDB tables and indexesinnobackupex: from original InnoDB data directory '/var/lib/mysql’innobackupex: Backing up as tar stream ‘ibdata1’>> log scanned up to (190 953625957)>> log scanned up to (190 953658449)>> log scanned up to (190 953680268)

[many more log lines like this]
and then finally :

log scanned up to (190 957269630)120215 13:14:04 innobackupex: Starting mysql with options: --password=xxxxxxxx --user=‘backups’ --unbuffered --120215 13:14:04 innobackupex: Connected to database with mysql child process (pid=4931)>> log scanned up to (190 957301085)innobackupex: Error: mysql child process has died: ERROR 1045 (28000) at line 4: Access denied for user ‘backups’@‘localhost’ (using password: YES) while waiting for reply to MySQL request: ‘STOP SLAVE SQL_THREAD;’ at /usr/bin/innobackupex line 349.

Obviously the credentials haven’t changed since it started successfully, and I can manually connect with them right after getting this message.
What’s the problem here ?

Thanks for any help !

Here are the privileges for my backups user btw :

mysql> select * from user where user=‘backups’ \G*************************** 1. row *************************** Host: localhost User: backups Password: xxxxxxxx Select_priv: N Insert_priv: N Update_priv: N Delete_priv: N Create_priv: N Drop_priv: N Reload_priv: Y Shutdown_priv: N Process_priv: N File_priv: N Grant_priv: N References_priv: N Index_priv: N Alter_priv: N Show_db_priv: N Super_priv: NCreate_tmp_table_priv: N Lock_tables_priv: Y Execute_priv: N Repl_slave_priv: N Repl_client_priv: Y Create_view_priv: N Show_view_priv: N Create_routine_priv: N Alter_routine_priv: N Create_user_priv: N Event_priv: N Trigger_priv: N ssl_type: ssl_cipher: x509_issuer: x509_subject: max_questions: 0 max_updates: 0 max_connections: 0 max_user_connections: 01 row in set (0.00 sec)

Also wondering about something :

The first time I ran innobackupex, I did so with --stream=tar /var/lib/mysql/
Does this mean I set the backup destination directory to /var/lib/mysql (where my DB lives) and that could have possibly overwritten ibdata1 and other files, even though I was in stream mode ?
Any chance I got something corrupted doing this ?

Answering my own question : I was probably missing Super_priv on this user to start/stop the sql thread.
I had set this user’s privs according to the doc, but they didn’t seem to cover that extra privilege needed for --safe-slave-backup.
Testing again now…

I am getting the same issue. I’ve ruled out the account permissions by using the root account with full permissions to initiate the backup and the mysql root account with full permissions to the database.

332 #
333 # Die subroutine kills all child processes and exits this process.
334 # This subroutine takes the same argument as the built-in die function.
335 # Parameters:
336 # message string which is printed to stdout
337 #
338 sub Die {
339 my $message = shift;
340 my $extra_info = ‘’;
342 # kill all child processes of this process
343 kill_child_processes();
345 if ($current_mysql_request) {
346 $extra_info = " while waiting for reply to MySQL request:" .
347 " ‘$current_mysql_request’";
348 }
349 die “$prefix Error: $message$extra_info”;
350 }

from what I see in the code, there is a sub process that is not being killed correctly. I’m still looking into what sub process that might be.

There is probably a buggy process of starting the ‘mysql’ child process with the wrong authentication options.

You may be able to work around this by setting the options in the [client] section of your $HOME/.my.cnf file.