Feature 307 revised - Githubissues

gitmstoute commented 5 years ago

@ShahriyarR here is a much cleaner set of commits.

8364b41 - Introduce ProcessRunner class/run_command() function.

The run_command() function basically wraps the call to subprocess, logs the PID/stdout/stderr of the subprocess in realtime, and returns True/False based on the subprocess exit code.
It provides a uniform logging format no matter which command is called (for instance, xtrabackup or tar), and only a single place to fix the logic if there is an error.

daf8905 - This changes logging output to include .py file and line#.

It's not necessary for resolving #307 however it helped me during debugging.

641cc99 - In prepare.py, use ProcessRunner() instead of subprocess.getstatusoutput(), to resolve #307 for all xtrabackup commands.

b91a919 - In backuper.py, use ProcessRunner() instead of subprocess.getstatusoutput(), to resolve #307 for all xtrabackup commands.

Also use ProcessRunner() for tar call, which can also take time and people might like logging for.
Small change to add_tag(); if self.tag() is included now, and fewer arguments required. it is not necessary for resolving #307.
In all_backup(), replaced the outermost if statement with an assertion on check_env_obj.check_all_env(). (Helps reduce indentation).

Lastly, I updated some variable names which IMO are clearer (for instance, 'args' -> 'xtrabackup_cmd').

ShahriyarR commented 5 years ago

What a wonderful changes :) I am going to test them now. Thank you for contribution.

ShahriyarR commented 5 years ago

Got weird error:

$ git fetch origin pull/349/head:PR349
$ git checkout PR349
$ python setup.py install

Result:

$ /home/shako/REPOS/MySQL-AutoXtraBackup/.venv/bin/autoxtrabackup --backup -v -l DEBUG --defaults-file=/home/shako/.autoxtrabackup/autoxtrabackup.cnf
Traceback (most recent call last):
  File "/home/shako/REPOS/MySQL-AutoXtraBackup/.venv/bin/autoxtrabackup", line 11, in <module>
    load_entry_point('mysql-autoxtrabackup==1.5.5', 'console_scripts', 'autoxtrabackup')()
  File "/home/shako/REPOS/MySQL-AutoXtraBackup/.venv/lib/python3.6/site-packages/pkg_resources/__init__.py", line 480, in load_entry_point
    return get_distribution(dist).load_entry_point(group, name)
  File "/home/shako/REPOS/MySQL-AutoXtraBackup/.venv/lib/python3.6/site-packages/pkg_resources/__init__.py", line 2693, in load_entry_point
    return ep.load()
  File "/home/shako/REPOS/MySQL-AutoXtraBackup/.venv/lib/python3.6/site-packages/pkg_resources/__init__.py", line 2324, in load
    return self.resolve()
  File "/home/shako/REPOS/MySQL-AutoXtraBackup/.venv/lib/python3.6/site-packages/pkg_resources/__init__.py", line 2330, in resolve
    module = __import__(self.module_name, fromlist=['__name__'], level=0)
  File "/home/shako/REPOS/MySQL-AutoXtraBackup/.venv/lib/python3.6/site-packages/mysql_autoxtrabackup-1.5.5-py3.6.egg/autoxtrabackup.py", line 2, in <module>
    from master_backup_script.backuper import Backup
  File "/home/shako/REPOS/MySQL-AutoXtraBackup/.venv/lib/python3.6/site-packages/mysql_autoxtrabackup-1.5.5-py3.6.egg/master_backup_script/__init__.py", line 1, in <module>
    from master_backup_script import backuper
  File "/home/shako/REPOS/MySQL-AutoXtraBackup/.venv/lib/python3.6/site-packages/mysql_autoxtrabackup-1.5.5-py3.6.egg/master_backup_script/backuper.py", line 21, in <module>
    from backup_prepare.prepare import Prepare
  File "/home/shako/REPOS/MySQL-AutoXtraBackup/.venv/lib/python3.6/site-packages/mysql_autoxtrabackup-1.5.5-py3.6.egg/backup_prepare/prepare.py", line 14, in <module>
    from process_runner.process_runner import  ProcessRunner
ModuleNotFoundError: No module named 'process_runner'

But with PyCharm Configuratin run it works :)

/home/shako/REPOS/MySQL-AutoXtraBackup/.venv/bin/python /home/shako/REPOS/MySQL-AutoXtraBackup/.venv/bin/autoxtrabackup -v -l DEBUG --backup
2019-01-15 14:22:43 DEBUG    [__init__.py:71] <pid.PidFile object at 0x7f1bff1bd7c8> entering setup
2019-01-15 14:22:43 DEBUG    [__init__.py:161] <pid.PidFile object at 0x7f1bff1bd7c8> create pidfile: /tmp/MySQL-AutoXtraBackup/autoxtrabackup.pid
2019-01-15 14:22:43 DEBUG    [__init__.py:148] <pid.PidFile object at 0x7f1bff1bd7c8> check pidfile: /tmp/MySQL-AutoXtraBackup/autoxtrabackup.pid
2019-01-15 14:22:43 DEBUG    [check_env.py:49] Running mysqladmin command -> /usr/bin/mysqladmin --defaults-file= --user=root --password='*' status --host=127.0.0.1 --port=3306
2019-01-15 14:22:43 DEBUG    [check_env.py:54] OK: Server is Up and running
2019-01-15 14:22:43 DEBUG    [check_env.py:81] OK: /usr/bin/mysql exists
2019-01-15 14:22:43 DEBUG    [check_env.py:93] OK: /usr/bin/mysqladmin exists
2019-01-15 14:22:43 DEBUG    [check_env.py:66] Skipping my.cnf check, because it is not specified
2019-01-15 14:22:43 DEBUG    [check_env.py:105] OK: XtraBackup exists
2019-01-15 14:22:43 DEBUG    [check_env.py:118] OK: Main backup directory exists
2019-01-15 14:22:43 DEBUG    [check_env.py:162] OK: Full Backup directory exists
2019-01-15 14:22:43 DEBUG    [check_env.py:182] OK: Increment directory exists
2019-01-15 14:22:43 DEBUG    [check_env.py:215] OK: Check status
2019-01-15 14:22:43 DEBUG    [backuper.py:736] - - - - You have a full backup that is less than 86400 seconds old. - - - -
2019-01-15 14:22:43 DEBUG    [backuper.py:737] - - - - We will take an incremental one based on recent Full Backup - - - -
2019-01-15 14:22:46 DEBUG    [backuper.py:589] Using xbstream to extract and decrypt from inc_backup.stream!
2019-01-15 14:22:46 DEBUG    [backuper.py:602] The following xbstream command will be executed /usr/bin/xbstream -x --parallel=100 --decrypt=AES256 --encrypt-key=VVTBwgM4UhwkTTV98fhuj+D1zyWoA89K --encrypt-threads=4 < /home/shako/XB_TEST/backup_dir/inc/2019-01-15_14-13-32/inc_backup.stream -C /home/shako/XB_TEST/backup_dir/inc/2019-01-15_14-13-32
2019-01-15 14:22:46 DEBUG    [backuper.py:606] OK: XBSTREAM command succeeded.
2019-01-15 14:22:46 WARNING  [backuper.py:661] Streaming is enabled!

ShahriyarR commented 5 years ago

@gitmstoute Okay found the problem. So in setup.py file you need to add process_runner as package. Could you please replace this:

packages=['general_conf', 'backup_prepare', 'partial_recovery', 'master_backup_script', 'prepare_env_test_mode'],

With this:

packages=['general_conf', 'backup_prepare', 'partial_recovery', 'master_backup_script', 'prepare_env_test_mode', 'process_runner'],

And push to your branch?

gitmstoute commented 5 years ago

@ShahriyarR Good catch, thanks. I Just pushed that.

ShahriyarR commented 5 years ago

@gitmstoute Thanks. Another thing maybe it is non-trivial thing to do but, just asking your opinion. Thinking from user side we have bunch of outputs with same file and line number:

xtrabackup: uses posix_fadvise().
2019-01-15 14:57:23 DEBUG    [process_runner.py:51] SPC xtrabackup | xtrabackup: uses posix_fadvise().
xtrabackup: cd to /var/lib/mysql/
2019-01-15 14:57:23 DEBUG    [process_runner.py:51] SPC xtrabackup | xtrabackup: cd to /var/lib/mysql/
xtrabackup: open files limit requested 0, set to 1024
2019-01-15 14:57:23 DEBUG    [process_runner.py:51] SPC xtrabackup | xtrabackup: open files limit requested 0, set to 1024
xtrabackup: using the following InnoDB configuration:
2019-01-15 14:57:23 DEBUG    [process_runner.py:51] SPC xtrabackup | xtrabackup: using the following InnoDB configuration:
xtrabackup:   innodb_data_home_dir = .
2019-01-15 14:57:23 DEBUG    [process_runner.py:51] SPC xtrabackup | xtrabackup:   innodb_data_home_dir = .
xtrabackup:   innodb_data_file_path = ibdata1:12M:autoextend
2019-01-15 14:57:23 DEBUG    [process_runner.py:51] SPC xtrabackup | xtrabackup:   innodb_data_file_path = ibdata1:12M:autoextend
xtrabackup:   innodb_log_group_home_dir = ./
2019-01-15 14:57:23 DEBUG    [process_runner.py:51] SPC xtrabackup | xtrabackup:   innodb_log_group_home_dir = ./
xtrabackup:   innodb_log_files_in_group = 2
2019-01-15 14:57:23 DEBUG    [process_runner.py:51] SPC xtrabackup | xtrabackup:   innodb_log_files_in_group = 2
xtrabackup:   innodb_log_file_size = 50331648
2019-01-15 14:57:23 DEBUG    [process_runner.py:51] SPC xtrabackup | xtrabackup:   innodb_log_file_size = 50331648
InnoDB: Number of pools: 1
2019-01-15 14:57:23 DEBUG    [process_runner.py:51] SPC xtrabackup | InnoDB: Number of pools: 1
190115 14:57:23 >> log scanned up to (16708635)
2019-01-15 14:57:23 DEBUG    [process_runner.py:51] SPC xtrabackup | 190115 14:57:23 >> log scanned up to (16708635)
xtrabackup: Generating a list of tablespaces

If you noticed, [process_runner.py:51] repeated. Is it possible to eliminate this for process_runner.py itself?

gitmstoute commented 5 years ago

@ShahriyarR I'm sure it's possible but I can't look right now. Maybe in another feature?

ShahriyarR commented 5 years ago

@gitmstoute yes sure. I am going to do few more tests and then merge it to release_v1.5.5 branch. Then release the version as you did great changes. Thank you again for contribution - now we more professionally looking commandline tool. Please feel free to test and find extra bugs, features that we can implement further.

ShahriyarR commented 5 years ago

@gitmstoute I have found another problem:

2019-01-16_13-23-01     Full    OK      2019-01-16_13-23-05     2,8M    'Full backup'
2019-01-16_13-23-01     Inc     OK      2019-01-16_13-23-44     492K    'Inc1 backup'
2019-01-16_13-23-01     Inc     OK      2019-01-16_13-25-02     492K    'Inc2 backup'

In backup tags, increment backups are marked as full. Please see first column. It will fail during prepare stage for sure. Could you please revisit your add_tag() changes? For final tests you can use following scenario: Take 3 backups:

--tag='Full Backup'
--tag='Inc1 Backup'
--tag='Inc2 Backup'

Then try to prepare them using --tag='Inc2 Backup'

gitmstoute commented 5 years ago

@ShahriyarR Thanks for catching that! I believe latest commit resolves this.

cat backup_tags.txt  
2019-01-16_11-39-54 Full    OK  2019-01-16_11-40-38 1.8G    'xtest'  
2019-01-16_11-41-18 Inc OK  2019-01-16_11-41-35 7.0M    'inc1'  
2019-01-16_11-41-47 Inc OK  2019-01-16_11-42-04 7.0M    'inc2'  
2019-01-16_11-42-11 Inc OK  2019-01-16_11-42-28 7.0M    'inc3'  
2019-01-16_11-42-37 Inc OK  2019-01-16_11-42-54 7.0M    'inc4'

BarbzYHOOL commented 5 years ago

awesome guys

ShahriyarR / MySQL-AutoXtraBackup

Feature 307 revised #349