MySQL Bugs: #56562: Not all the failed backup operations are logged in MEB logs.

Bug #56562	Not all the failed backup operations are logged in MEB logs.
Submitted:	4 Sep 2010 20:03	Modified:	30 Sep 2010 22:31
Reporter:	Hema Sridharan	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Enterprise Backup	Severity:	S3 (Non-critical)
Version:	MEB3.5	OS:	Linux (64 bit)
Assigned to:	Satya B	CPU Architecture:	Any

Description:
* Create some database, tables and load data
* Execute innobackup and simulate for failure such as using invalid compression options.
* The backup will fail but this is not logged in history logs.
* Ideally this should also be logged.

How to repeat:
The following failed operations are not logged in backup history  table.

Run the test in mysql-5.1-meb tree

--echo #
--echo # Run innobackup using invalid options like 'comment'
--error 1
--exec $INNOBACKUP --port=$MASTER_MYPORT --user=root --comment='TESTING' $SERVER_CNF $BACKUP_TARGET_DIR > $BACKUP_LOG 2>&1
--echo # Innobackup errors out
--echo # innobackup: unknown variable 'comment=TESTING'

--echo # Execute backup with invalid compression values
--echo ....
--error 1
--exec $INNOBACKUP --compress 11 --no-timestamp $SERVER_CNF $BACKUP_TARGET_DIR --port=$MASTER_MYPORT --user=root > $BACKUP_LOG

To check if the failed operations is logged, verify using select statement.
SELECT exit_state, last_error, last_error_code FROM mysql.backup_history;

It is also to be noted that some failed innobackup operations are logged (using invalid sleep options)

Suggested fix:
All the failed backup operations should be logged.

IMHO we do not need to log a backup attempt if it fails due to
- the backup software (MEB) is not installed on the machine,
- the command is mistyped, e.g. mysql_backoop,
- mistyped or unknown options,
- illegal arguments as long as they provoke a "usage" display,
- use of the --help or --version options,
- missing or invalid user credentials (--user, --password),
- invalid arguments to --port or --socket,
- bad arguments to --ibbackup.

In the above cases, a backup operation does not even try to start.
Hence there is no need to log it.

I disagree. If the user expects a backup to happen, and it doesn't, the reason doesn't matter. Failure to even start, is a failed backup as far as the user is concerned. If MEB can write to the log during this failure condition it should, otherwise there is no way to determine why a backup is failing to run, especially when run in an unattended fashion (from cron, for example).

Hi, 

I made to patch to log command line failure too.

- the backup software (MEB) is not installed on the machine,
   Wow! We cannot log for sure ;)

- the command is mistyped, e.g. mysql_backoop,
   We cannot log this too :)

- mistyped or unknown options
   Can be logged after making few changes.

- illegal arguments as long as they provoke a "usage" display,
    Almost all (will explain the reason for 'Almost' in next comment)

- use of the --help or --version options,
    Cannot be logged. 

- missing or invalid user credentials (--user, --password),
   Cannot be logged because connection to the server cannot be made
   Cannot be logged even if the user is not 'root', we create table in mysql
   database(innobackup will also fail)
   
- invalid arguments to --port or --socket,
   Cannot be logged for above reason.

- bad arguments to --ibbackup.
   These are logged with message "ibbackup process has died"

Hema,

--echo #
--echo # Run innobackup using invalid options like 'comment'
--error 1
--exec $INNOBACKUP --port=$MASTER_MYPORT --user=root --comment='TESTING' $SERVER_CNF
$BACKUP_TARGET_DIR > $BACKUP_LOG 2>&1
--echo # Innobackup errors out
--echo # innobackup: unknown variable 'comment=TESTING'

This can be logged with 'Bad command arguments' message only. 
The reason why the exact message is not logged is because this
is from 'mysys with WME(Write Message on Error)' library.

--echo # Execute backup with invalid compression values
--echo ....
--error 1
--exec $INNOBACKUP --compress 11 --no-timestamp $SERVER_CNF $BACKUP_TARGET_DIR
--port=$MASTER_MYPORT --user=root > $BACKUP_LOG

I got invalid number of command line options, it is logged :)

Then I realised the option is --compress=11  which succeeded.
innobackup converts values out of range(1 to 9) to within range.
with a warning in the log.

Now to the reason for 'Almost':

I am setting compress to Non-integer

CASE 1:
=======

--exec $INNOBACKUP --compress=junkie --no-timestamp $SERVER_CNF $BACKUP_TARGET_DIR --port=$MASTER_MYPORT --user=root  > $BACKUP_LOG 2>&1

This is not logged as handle_options() from mysys exits as soon as it is not able to set 'junkie' to compress option and it stops parsing other options.

So, --user and --port are not parsed  and connection to the server cannot be 
made :(

CASE 2:
=======

--exec $INNOBACKUP  --no-timestamp $SERVER_CNF $BACKUP_TARGET_DIR --port=$MASTER_MYPORT --user=root --compress=junkie > $BACKUP_LOG 2>&1

This can be logged as the user, port are parsed first and compress option fails 
later.

Setting thava and ritheesh as reviewers (WL#5495 Reviewers)

revno: 235
revision-id: satya.bn@sun.com-20100917052338-u7lnlfc6n0t0b1fk

meb-3.5.next

Bug does not appear in any released version. No changelog entry needed.