Merge "Fix logrotate tests"

This commit is contained in:
Jenkins
2016-03-29 16:58:42 +00:00
committed by Gerrit Code Review
2 changed files with 238 additions and 247 deletions

View File

@@ -169,20 +169,27 @@ class SSHManager(object):
result['stderr_str'] = ''.join(result['stderr']).strip() result['stderr_str'] = ''.join(result['stderr']).strip()
result['stderr_len'] = len(result['stderr']) result['stderr_len'] = len(result['stderr'])
if result['exit_code'] not in assert_ec_equal: details_log = (
error_details = { "Host: {host}\n"
'command': cmd, "Command: '{cmd}'\n"
'host': ip, "Exit code: {code}\n"
'stdout': result['stdout'], "STDOUT:\n{stdout}\n"
'stderr': result['stderr'], "STDERR:\n{stderr}".format(
'exit_code': result['exit_code']} host=ip, cmd=cmd, code=result['exit_code'],
stdout=result['stdout_str'], stderr=result['stderr_str']
))
error_msg = (err_msg or "Unexpected exit_code returned:" if result['exit_code'] not in assert_ec_equal:
" actual {0}, expected {1}." error_msg = (
.format(error_details['exit_code'], err_msg or
' '.join(map(str, assert_ec_equal)))) "Unexpected exit_code returned: actual {0}, expected {1}."
log_msg = ("{0} Command: '{1}' " "".format(
"Details: {2}".format(error_msg, cmd, error_details)) result['exit_code'],
' '.join(map(str, assert_ec_equal))))
log_msg = (
"{0} Command: '{1}' "
"Details:\n{2}".format(
error_msg, cmd, details_log))
logger.error(log_msg) logger.error(log_msg)
if raise_on_assert: if raise_on_assert:
raise UnexpectedExitCode(cmd, raise UnexpectedExitCode(cmd,
@@ -190,6 +197,8 @@ class SSHManager(object):
assert_ec_equal, assert_ec_equal,
stdout=result['stdout_str'], stdout=result['stdout_str'],
stderr=result['stderr_str']) stderr=result['stderr_str'])
else:
logger.debug(details_log)
if jsonify: if jsonify:
try: try:

View File

@@ -84,8 +84,8 @@ class TestAdminNode(TestBasic):
""" """
self.env.revert_snapshot("empty") self.env.revert_snapshot("empty")
with self.env.d_env.get_admin_remote() as remote: ps_output = self.ssh_manager.execute(
ps_output = remote.execute('ps ax')['stdout'] self.ssh_manager.admin_ip, 'ps ax')['stdout']
astute_master = [ astute_master = [
master for master in ps_output if 'astute master' in master] master for master in ps_output if 'astute master' in master]
logger.info("Found astute processes: {:s}".format(astute_master)) logger.info("Found astute processes: {:s}".format(astute_master))
@@ -100,53 +100,49 @@ class TestAdminNode(TestBasic):
@test(groups=["logrotate"]) @test(groups=["logrotate"])
class TestLogrotateBase(TestBasic): class TestLogrotateBase(TestBasic):
@staticmethod @staticmethod
def generate_file(remote, name, path, size): def no_error_in_log(log_txt):
checker = re.compile(r'\s+(error)[: \n\t]+', flags=re.IGNORECASE)
return len(checker.findall(log_txt)) == 0
def generate_file(self, remote_ip, name, path, size):
cmd = 'cd {0} && fallocate -l {1} {2}'.format(path, size, name) cmd = 'cd {0} && fallocate -l {1} {2}'.format(path, size, name)
result = remote.execute(cmd) self.ssh_manager.execute_on_remote(remote_ip, cmd)
assert_equal(0, result['exit_code'],
'Command {0} execution failed. '
'Execution result is: {1}'.format(cmd, result))
@staticmethod def execute_logrotate_cmd(
def execute_logrotate_cmd(remote, force=True, cmd=None, exit_code=None): self, remote_ip, force=True, cmd=None, any_exit_code=False):
if not cmd: if not cmd:
cmd = 'logrotate -v {0} /etc/logrotate.conf'.format( cmd = 'logrotate -v {0} /etc/logrotate.conf'.format(
'-f' if force else "") '-f' if force else "")
result = remote.execute(cmd) result = self.ssh_manager.execute_on_remote(
logger.debug( remote_ip, cmd, raise_on_assert=not any_exit_code)
'Results of command {0} execution exit_code:{1} '
'stdout: {2} stderr: {3}'.format(
cmd, result['exit_code'], result['stdout'], result['stderr']))
if not exit_code:
assert_equal(0, result['exit_code'],
'Command {0} execution failed. '
'Execution result is: {1}'.format(cmd, result))
else:
return result
def check_free_space(self, remote, return_as_is=None): assert_equal(
result = remote.execute( True, self.no_error_in_log(result['stderr_str']),
'logrotate failed with:\n{0}'.format(result['stderr_str']))
logger.info('Logrotate: success')
return result
def check_free_space(self, remote_ip, return_as_is=None):
result = self.ssh_manager.execute_on_remote(
remote_ip,
'python -c "import os; ' 'python -c "import os; '
'stats=os.statvfs(\'/var/log\'); ' 'stats=os.statvfs(\'/var/log\'); '
'print stats.f_bavail * stats.f_frsize"') 'print stats.f_bavail * stats.f_frsize"',
assert_equal(0, result['exit_code'], err_msg='Failed to check free space!'
'Failed to check free ' )
'space with {0}'. format(result))
if not return_as_is: if not return_as_is:
return self.bytestogb(int(result['stdout'][0])) return self.bytestogb(int(result['stdout'][0]))
else: else:
return int(result['stdout'][0]) return int(result['stdout'][0])
def check_free_inodes(self, remote): def check_free_inodes(self, remote_ip):
result = remote.execute( result = self.ssh_manager.execute_on_remote(
remote_ip,
'python -c "import os; ' 'python -c "import os; '
'stats=os.statvfs(\'/var/log\'); ' 'stats=os.statvfs(\'/var/log\'); '
'print stats.f_ffree"') 'print stats.f_ffree"',
assert_equal(0, result['exit_code'], err_msg='Failed to check free inodes!')
'Failed to check free '
'inodes with {0}'. format(result))
return self.bytestogb(int(result['stdout'][0])) return self.bytestogb(int(result['stdout'][0]))
@staticmethod @staticmethod
@@ -161,15 +157,14 @@ class TestLogrotateBase(TestBasic):
return format(value, '.1f'), s return format(value, '.1f'), s
return data, 'B' return data, 'B'
@staticmethod def create_old_file(self, remote_ip, name):
def create_old_file(remote, name):
one_week_old = datetime.datetime.now() - datetime.timedelta(days=7) one_week_old = datetime.datetime.now() - datetime.timedelta(days=7)
res = remote.execute( result = self.ssh_manager.execute_on_remote(
'touch {0} -d {1}'.format(name, one_week_old)) remote_ip,
assert_equal(0, res['exit_code'], 'touch {0} -d {1}'.format(name, one_week_old),
'Failed to create old ' err_msg='Failed to create old file!'
'file with next result: {0}'.format(res)) )
return res return result
@test(depends_on=[SetupEnvironment.setup_master], @test(depends_on=[SetupEnvironment.setup_master],
groups=["test_logrotate"]) groups=["test_logrotate"])
@@ -189,66 +184,61 @@ class TestLogrotateBase(TestBasic):
""" """
self.show_step(1, initialize=True) self.show_step(1, initialize=True)
self.env.revert_snapshot("empty") self.env.revert_snapshot("empty")
with self.env.d_env.get_admin_remote() as remote:
# get data before logrotate admin_ip = self.ssh_manager.admin_ip
self.show_step(2)
free, suff = self.check_free_space(remote)
free_inodes, i_suff = self.check_free_inodes(remote) # get data before logrotate
logger.debug('Free inodes before file ' self.show_step(2)
'creation: {0}{1}'.format(free_inodes, i_suff)) free, suff = self.check_free_space(admin_ip)
self.show_step(3)
self.generate_file(
remote, size='2G',
path='/var/log/',
name='messages')
# Get free space after file creation free_inodes, i_suff = self.check_free_inodes(admin_ip)
free2, suff2 = self.check_free_space(remote) logger.debug('Free inodes before file '
assert_true( 'creation: {0}{1}'.format(free_inodes, i_suff))
free2 < free, self.show_step(3)
'File was not created. Free space ' self.generate_file(
'before creation {0}{1}, ' admin_ip, size='2G',
'free space after ' path='/var/log/',
'creation {2}{3}'.format(free, suff, free2, suff2)) name='messages')
self.show_step(4) # Get free space after file creation
self.execute_logrotate_cmd(remote, force=False) free2, suff2 = self.check_free_space(admin_ip)
assert_true(
free2 < free,
'File was not created. Free space '
'before creation {0}{1}, '
'free space after '
'creation {2}{3}'.format(free, suff, free2, suff2))
free3, suff3 = self.check_free_space(remote) self.show_step(4)
logger.debug('Free space after first ' self.execute_logrotate_cmd(admin_ip, force=False)
'rotation {0} {1}'.format(free3, suff3))
res = self.execute_logrotate_cmd(remote, exit_code=1)
# Expect 1 exit code here, according free3, suff3 = self.check_free_space(admin_ip)
# to some rotated logs are skipped to rotate logger.debug('Free space after first '
# second run. That's caused 1 'rotation {0} {1}'.format(free3, suff3))
assert_equal(1, res['exit_code'])
assert_equal(
False, 'error' in res['stderr'],
'Second run of logrotate failed'
' with {0}'.format(res['stderr']))
free4, suff4 = self.check_free_space(remote) # Allow any exit code, but check real status later
free_inodes4, i_suff4 = self.check_free_inodes(remote) # Logrotate can return fake-fail on second run
logger.info('Free inodes after logrotation:' self.execute_logrotate_cmd(admin_ip, any_exit_code=True)
' {0}{1}'.format(free_inodes4, i_suff4))
assert_true( free4, suff4 = self.check_free_space(admin_ip)
free4 > free2, free_inodes4, i_suff4 = self.check_free_inodes(admin_ip)
'Logs were not rotated. ' logger.info('Free inodes after logrotation:'
'Rotate was executed 2 times. ' ' {0}{1}'.format(free_inodes4, i_suff4))
'Free space after file creation: {0}{1}, '
'after rotation {2}{3} free space before rotation {4}'
'{5}'.format(free2, suff2, free4, suff4, free, suff))
assert_equal( assert_true(
(free_inodes, i_suff), free4 > free2,
(free_inodes4, i_suff4), 'Logs were not rotated. '
'Unexpected free inodes count. Before log rotate was: {0}{1}' 'Rotate was executed 2 times. '
' after logrotation: {2}{3}'.format( 'Free space after file creation: {0}{1}, '
free_inodes, i_suff, free_inodes4, i_suff4)) 'after rotation {2}{3} free space before rotation {4}'
'{5}'.format(free2, suff2, free4, suff4, free, suff))
assert_equal(
(free_inodes, i_suff),
(free_inodes4, i_suff4),
'Unexpected free inodes count. Before log rotate was: {0}{1}'
' after logrotation: {2}{3}'.format(
free_inodes, i_suff, free_inodes4, i_suff4))
self.env.make_snapshot("test_logrotate") self.env.make_snapshot("test_logrotate")
@test(depends_on=[SetupEnvironment.setup_master], @test(depends_on=[SetupEnvironment.setup_master],
@@ -269,54 +259,55 @@ class TestLogrotateBase(TestBasic):
""" """
self.show_step(1, initialize=True) self.show_step(1, initialize=True)
self.env.revert_snapshot("empty") self.env.revert_snapshot("empty")
with self.env.d_env.get_admin_remote() as remote:
# get data before logrotate admin_ip = self.ssh_manager.admin_ip
self.show_step(2)
free, suff = self.check_free_space(remote)
free_inodes, i_suff = self.check_free_inodes(remote)
logger.debug('Free inodes before file '
'creation: {0}{1}'.format(free_inodes, i_suff))
self.show_step(3)
self.generate_file(
remote, size='2G',
path='/var/log/',
name='ostf-test.log')
free2, suff2 = self.check_free_space(remote) # get data before logrotate
assert_true( self.show_step(2)
free2 < free, free, suff = self.check_free_space(admin_ip)
'File was not created. Free space ' free_inodes, i_suff = self.check_free_inodes(admin_ip)
'before creation {0}{1}, ' logger.debug('Free inodes before file '
'free space after ' 'creation: {0}{1}'.format(free_inodes, i_suff))
'creation {2}{3}'.format(free, suff, free2, suff2)) self.show_step(3)
self.show_step(4) self.generate_file(
self.execute_logrotate_cmd(remote, cmd='/usr/bin/fuel-logrotate') admin_ip, size='2G',
self.show_step(5) path='/var/log/',
free3, suff3 = self.check_free_space(remote) name='ostf-test.log')
free_inodes3, i_suff3 = self.check_free_inodes(remote)
logger.info('Free inodes after logrotation:'
' {0}{1}'.format(free_inodes3, i_suff3))
assert_true( free2, suff2 = self.check_free_space(admin_ip)
free3 > free2, assert_true(
'Logs were not rotated. ' free2 < free,
'Free space before rotation: {0}{1}, ' 'File was not created. Free space '
'after rotation {2}{3}'.format(free2, suff2, free3, suff3)) 'before creation {0}{1}, '
'free space after '
'creation {2}{3}'.format(free, suff, free2, suff2))
self.show_step(4)
self.execute_logrotate_cmd(admin_ip, cmd='/usr/bin/fuel-logrotate')
self.show_step(5)
free3, suff3 = self.check_free_space(admin_ip)
free_inodes3, i_suff3 = self.check_free_inodes(admin_ip)
logger.info('Free inodes after logrotation:'
' {0}{1}'.format(free_inodes3, i_suff3))
assert_equal( assert_true(
(free_inodes, i_suff), free3 > free2,
(free_inodes3, i_suff3), 'Logs were not rotated. '
'Unexpected free inodes count. Before log rotate was: {0}{1}' 'Free space before rotation: {0}{1}, '
' after logrotation: {2}{3}'.format( 'after rotation {2}{3}'.format(free2, suff2, free3, suff3))
free_inodes, i_suff, free_inodes3, i_suff3))
assert_equal(
(free_inodes, i_suff),
(free_inodes3, i_suff3),
'Unexpected free inodes count. Before log rotate was: {0}{1}'
' after logrotation: {2}{3}'.format(
free_inodes, i_suff, free_inodes3, i_suff3))
self.env.make_snapshot("test_fuel_nondaily_logrotate") self.env.make_snapshot("test_fuel_nondaily_logrotate")
@test(depends_on=[SetupEnvironment.setup_master], @test(depends_on=[SetupEnvironment.setup_master],
groups=["test_logrotate_101MB"]) groups=["test_logrotate_101MB"])
@log_snapshot_after_test @log_snapshot_after_test
def test_log_rotation_101MB(self): def test_log_rotation_101mb(self):
"""Logrotate with logrotate.conf for 101MB size file on master node """Logrotate with logrotate.conf for 101MB size file on master node
Scenario: Scenario:
@@ -331,70 +322,65 @@ class TestLogrotateBase(TestBasic):
""" """
self.show_step(1, initialize=True) self.show_step(1, initialize=True)
self.env.revert_snapshot("empty") self.env.revert_snapshot("empty")
with self.env.d_env.get_admin_remote() as remote:
# get data before logrotate admin_ip = self.ssh_manager.admin_ip
self.show_step(2)
free, suff = self.check_free_space(remote)
free_inodes, i_suff = self.check_free_inodes(remote) # get data before logrotate
logger.debug('Free inodes before file ' self.show_step(2)
'creation: {0}{1}'.format(free_inodes, i_suff)) free, suff = self.check_free_space(admin_ip)
self.show_step(3)
self.generate_file(
remote, size='101M',
path='/var/log/',
name='messages')
free2, suff2 = self.check_free_space(remote) free_inodes, i_suff = self.check_free_inodes(admin_ip)
assert_true( logger.debug('Free inodes before file '
free2 < free, 'creation: {0}{1}'.format(free_inodes, i_suff))
'File was not created. Free space ' self.show_step(3)
'before creation {0}{1}, ' self.generate_file(
'free space after ' admin_ip, size='101M',
'creation {2}{3}'.format(free, suff, free2, suff2)) path='/var/log/',
self.show_step(4) name='messages')
self.execute_logrotate_cmd(remote, force=False)
free3, suff3 = self.check_free_space(remote) free2, suff2 = self.check_free_space(admin_ip)
logger.debug('free space after first ' assert_true(
'rotation: {0}{1}'.format(free3, suff3)) free2 < free,
res = self.execute_logrotate_cmd(remote, exit_code=1) 'File was not created. Free space '
'before creation {0}{1}, '
'free space after '
'creation {2}{3}'.format(free, suff, free2, suff2))
self.show_step(4)
self.execute_logrotate_cmd(admin_ip, force=False)
# Expect 1 exit code here, according free3, suff3 = self.check_free_space(admin_ip)
# to some rotated logs are skipped to rotate logger.debug('free space after first '
# second run. That's caused 1 'rotation: {0}{1}'.format(free3, suff3))
assert_equal(1, res['exit_code'])
assert_equal(
False, 'error' in res['stderr'],
'Second run of logrotate failed'
' with {0}'.format(res['stderr']))
free4, suff4 = self.check_free_space(remote) # Allow any exit code, but check real status later
free_inodes4, i_suff4 = self.check_free_inodes(remote) # Logrotate can return fake-fail on second run
logger.info('Free inodes after logrotation:' self.execute_logrotate_cmd(admin_ip, any_exit_code=True)
' {0}{1}'.format(free_inodes4, i_suff4))
assert_true( free4, suff4 = self.check_free_space(admin_ip)
free4 > free2, free_inodes4, i_suff4 = self.check_free_inodes(admin_ip)
'Logs were not rotated. ' logger.info('Free inodes after logrotation:'
'Rotate was executed 2 times. ' ' {0}{1}'.format(free_inodes4, i_suff4))
'Free space after file creation: {0}{1}, '
'after rotation {2}{3} free space before rotation {4}'
'{5}'.format(free2, suff2, free4, suff4, free, suff))
assert_equal( assert_true(
(free_inodes, i_suff), free4 > free2,
(free_inodes4, i_suff4), 'Logs were not rotated. '
'Unexpected free inodes count. Before log rotate was: {0}{1}' 'Rotate was executed 2 times. '
' after logrotation: {2}{3}'.format( 'Free space after file creation: {0}{1}, '
free_inodes, i_suff, free_inodes4, i_suff4)) 'after rotation {2}{3} free space before rotation {4}'
'{5}'.format(free2, suff2, free4, suff4, free, suff))
assert_equal(
(free_inodes, i_suff),
(free_inodes4, i_suff4),
'Unexpected free inodes count. Before log rotate was: {0}{1}'
' after logrotation: {2}{3}'.format(
free_inodes, i_suff, free_inodes4, i_suff4))
self.env.make_snapshot("test_logrotate_101MB") self.env.make_snapshot("test_logrotate_101MB")
@test(depends_on=[SetupEnvironment.setup_master], @test(depends_on=[SetupEnvironment.setup_master],
groups=["test_logrotate_one_week_11MB"]) groups=["test_logrotate_one_week_11MB"])
@log_snapshot_after_test @log_snapshot_after_test
def test_log_rotation_one_week_11MB(self): def test_log_rotation_one_week_11mb(self):
"""Logrotate with logrotate.conf for 1 week old file with size 11MB """Logrotate with logrotate.conf for 1 week old file with size 11MB
Scenario: Scenario:
@@ -409,67 +395,63 @@ class TestLogrotateBase(TestBasic):
""" """
self.show_step(1, initialize=True) self.show_step(1, initialize=True)
self.env.revert_snapshot("empty") self.env.revert_snapshot("empty")
with self.env.d_env.get_admin_remote() as remote:
# get data before logrotate admin_ip = self.ssh_manager.admin_ip
self.show_step(2)
free = self.check_free_space(remote, return_as_is=True)
free_inodes, i_suff = self.check_free_inodes(remote) # get data before logrotate
logger.debug('Free inodes before file ' self.show_step(2)
'creation: {0}{1}'.format(free_inodes, i_suff)) free = self.check_free_space(admin_ip, return_as_is=True)
# create 1 week old empty file
self.create_old_file(remote, name='/var/log/messages') free_inodes, i_suff = self.check_free_inodes(admin_ip)
self.show_step(3) logger.debug('Free inodes before file '
self.generate_file( 'creation: {0}{1}'.format(free_inodes, i_suff))
remote, size='11M', # create 1 week old empty file
path='/var/log/',
name='messages')
free2 = self.check_free_space(remote, return_as_is=True) self.create_old_file(admin_ip, name='/var/log/messages')
assert_true( self.show_step(3)
free2 < free, self.generate_file(
'File was not created. Free space ' admin_ip, size='11M',
'before creation {0}, ' path='/var/log/',
'free space after ' name='messages')
'creation {1}'.format(free, free2))
self.show_step(4)
self.execute_logrotate_cmd(remote, force=False)
free3 = self.check_free_space(remote, return_as_is=True) free2 = self.check_free_space(admin_ip, return_as_is=True)
logger.debug('Free space after first' assert_true(
' rotation {0}'.format(free3)) free2 < free,
res = self.execute_logrotate_cmd(remote, exit_code=1) 'File was not created. Free space '
'before creation {0}, '
'free space after '
'creation {1}'.format(free, free2))
self.show_step(4)
self.execute_logrotate_cmd(admin_ip, force=False)
# Expect 1 exit code here, according free3 = self.check_free_space(admin_ip, return_as_is=True)
# to some rotated logs are skipped to rotate logger.debug('Free space after first'
# second run. That's caused 1 ' rotation {0}'.format(free3))
assert_equal(1, res['exit_code'])
assert_equal(
False, 'error' in res['stderr'],
'Second run of logrotate failed'
' with {0}'.format(res['stderr']))
self.show_step(5)
free4 = self.check_free_space(remote, return_as_is=True)
free_inodes4, i_suff4 = self.check_free_inodes(remote)
logger.info('Free inodes after logrotation:'
' {0}{1}'.format(free_inodes4, i_suff4))
assert_true( # Allow any exit code, but check real status later
free4 > free2, # Logrotate can return fake-fail on second run
'Logs were not rotated. ' self.execute_logrotate_cmd(admin_ip, any_exit_code=True)
'Rotate was executed 2 times. '
'Free space after file creation: {0}, '
'after rotation {1} free space before rotation'
'{2}'.format(free2, free4, free))
assert_equal( self.show_step(5)
(free_inodes, i_suff), free4 = self.check_free_space(admin_ip, return_as_is=True)
(free_inodes4, i_suff4), free_inodes4, i_suff4 = self.check_free_inodes(admin_ip)
'Unexpected free inodes count. Before log rotate was: {0}{1}' logger.info('Free inodes after logrotation:'
' after logrotation: {2}{3}'.format( ' {0}{1}'.format(free_inodes4, i_suff4))
free_inodes, i_suff, free_inodes4, i_suff4))
assert_true(
free4 > free2,
'Logs were not rotated. '
'Rotate was executed 2 times. '
'Free space after file creation: {0}, '
'after rotation {1} free space before rotation'
'{2}'.format(free2, free4, free))
assert_equal(
(free_inodes, i_suff),
(free_inodes4, i_suff4),
'Unexpected free inodes count. Before log rotate was: {0}{1}'
' after logrotation: {2}{3}'.format(
free_inodes, i_suff, free_inodes4, i_suff4))
self.env.make_snapshot("test_logrotate_one_week_11MB") self.env.make_snapshot("test_logrotate_one_week_11MB")