Log benign command errors as warns

Errors logged when an image/container was not found are misleading and
should become warnings instead. Only log errors for real execution
failures.

Change-Id: If23ee1b5b0211221c0dd547e95a0487ea8d04909
Signed-off-by: Bogdan Dobrelya <bdobreli@redhat.com>
(cherry picked from commit 861ed06128)
This commit is contained in:
Bogdan Dobrelya 2020-08-18 11:37:11 +02:00
parent 6f44509dcb
commit e3789cc2ea
2 changed files with 30 additions and 22 deletions

View File

@ -40,7 +40,7 @@ class BaseRunner(object):
'and will be removed in Train.') 'and will be removed in Train.')
@staticmethod @staticmethod
def execute(cmd, log=None, quiet=False): def execute(cmd, log=None, quiet=False, warn_only=False):
if not log: if not log:
log = common.configure_logging(__name__) log = common.configure_logging(__name__)
if not quiet: if not quiet:
@ -49,8 +49,12 @@ class BaseRunner(object):
stderr=subprocess.PIPE) stderr=subprocess.PIPE)
cmd_stdout, cmd_stderr = subproc.communicate() cmd_stdout, cmd_stderr = subproc.communicate()
if subproc.returncode != 0: if subproc.returncode != 0:
log.error('Error executing %s: returned %s' % (cmd, if warn_only:
subproc.returncode)) log.warning('Error executing %s: '
'returned %s' % (cmd, subproc.returncode))
else:
log.error('Error executing %s: '
'returned %s' % (cmd, subproc.returncode))
if not quiet: if not quiet:
log.debug(cmd_stdout) log.debug(cmd_stdout)
log.debug(cmd_stderr) log.debug(cmd_stderr)
@ -78,7 +82,8 @@ class BaseRunner(object):
'--filter', 'label=managed_by=%s' % self.managed_by, '--filter', 'label=managed_by=%s' % self.managed_by,
'--format', fmt '--format', fmt
] ]
cmd_stdout, cmd_stderr, returncode = self.execute(cmd, self.log) cmd_stdout, cmd_stderr, returncode = self.execute(
cmd, log=self.log, quiet=False, warn_only=True)
results = cmd_stdout.split() results = cmd_stdout.split()
if returncode != 0 or not results or results == ['']: if returncode != 0 or not results or results == ['']:
# NOTE(bogdando): also look by the historically used to # NOTE(bogdando): also look by the historically used to
@ -100,7 +105,8 @@ class BaseRunner(object):
'--filter', 'label=managed_by=%s' % self.managed_by, '--filter', 'label=managed_by=%s' % self.managed_by,
'--filter', 'label=config_id=%s' % conf_id '--filter', 'label=config_id=%s' % conf_id
] ]
cmd_stdout, cmd_stderr, returncode = self.execute(cmd, self.log) cmd_stdout, cmd_stderr, returncode = self.execute(
cmd, log=self.log, quiet=False, warn_only=True)
results = cmd_stdout.split() results = cmd_stdout.split()
if returncode != 0 or not results or results == ['']: if returncode != 0 or not results or results == ['']:
# NOTE(bogdando): also look by the historically used to # NOTE(bogdando): also look by the historically used to
@ -131,7 +137,7 @@ class BaseRunner(object):
cmd.append(output_format) cmd.append(output_format)
cmd.append(name) cmd.append(name)
(cmd_stdout, cmd_stderr, returncode) = self.execute( (cmd_stdout, cmd_stderr, returncode) = self.execute(
cmd, self.log, quiet) cmd, self.log, quiet, True)
if returncode != 0: if returncode != 0:
return return
try: try:
@ -172,7 +178,8 @@ class BaseRunner(object):
'--format', '--format',
'{{.Names}}' '{{.Names}}'
] ]
(cmd_stdout, cmd_stderr, returncode) = self.execute(cmd, self.log) (cmd_stdout, cmd_stderr, returncode) = self.execute(
cmd, log=self.log, quiet=False, warn_only=True)
if returncode == 0: if returncode == 0:
names = cmd_stdout.split() names = cmd_stdout.split()
if names: if names:
@ -255,7 +262,8 @@ class BaseRunner(object):
cmd.extend(( cmd.extend((
'--format', '{{.Names}} %s' % fmt '--format', '{{.Names}} %s' % fmt
)) ))
cmd_stdout, cmd_stderr, returncode = self.execute(cmd, self.log) cmd_stdout, cmd_stderr, returncode = self.execute(
cmd, log=self.log, quiet=False, warn_only=True)
results = cmd_stdout.split("\n") results = cmd_stdout.split("\n")
if returncode != 0 or not results or results == ['']: if returncode != 0 or not results or results == ['']:
# NOTE(bogdando): also look by the historically used to # NOTE(bogdando): also look by the historically used to
@ -462,12 +470,12 @@ class PodmanRunner(BaseRunner):
def image_exist(self, name, quiet=False): def image_exist(self, name, quiet=False):
cmd = ['podman', 'image', 'exists', name] cmd = ['podman', 'image', 'exists', name]
(_, _, returncode) = self.execute(cmd, self.log, quiet) (_, _, returncode) = self.execute(cmd, self.log, quiet, True)
return returncode == 0 return returncode == 0
def container_exist(self, name, quiet=False): def container_exist(self, name, quiet=False):
cmd = ['podman', 'container', 'exists', name] cmd = ['podman', 'container', 'exists', name]
(_, _, returncode) = self.execute(cmd, self.log, quiet) (_, _, returncode) = self.execute(cmd, self.log, quiet, True)
return returncode == 0 return returncode == 0
def container_running(self, container): def container_running(self, container):
@ -494,8 +502,8 @@ class PodmanRunner(BaseRunner):
# at the first retry, we will force a sync with the OCI runtime # at the first retry, we will force a sync with the OCI runtime
if self.cont_cmd == 'podman' and count == 2: if self.cont_cmd == 'podman' and count == 2:
chk_cmd.append('--sync') chk_cmd.append('--sync')
(cmd_stdout, cmd_stderr, returncode) = self.execute(chk_cmd, (cmd_stdout, cmd_stderr, returncode) = self.execute(
self.log) chk_cmd, log=self.log, quiet=False, warn_only=True)
if returncode != 0: if returncode != 0:
self.log.warning('Attempt %i Error when running ' self.log.warning('Attempt %i Error when running '

View File

@ -119,12 +119,12 @@ three-12345678 three''', '', 0),
# inspect existing image centos:6 # inspect existing image centos:6
mock.call( mock.call(
['docker', 'inspect', '--type', 'image', ['docker', 'inspect', '--type', 'image',
'--format', 'exists', 'centos:6'], mock.ANY, False '--format', 'exists', 'centos:6'], mock.ANY, False, True
), ),
# inspect and pull missing image centos:7 # inspect and pull missing image centos:7
mock.call( mock.call(
['docker', 'inspect', '--type', 'image', ['docker', 'inspect', '--type', 'image',
'--format', 'exists', 'centos:7'], mock.ANY, False '--format', 'exists', 'centos:7'], mock.ANY, False, True
), ),
# first pull attempt fails # first pull attempt fails
mock.call( mock.call(
@ -140,7 +140,7 @@ three-12345678 three''', '', 0),
'--filter', 'label=managed_by=tester', '--filter', 'label=managed_by=tester',
'--filter', 'label=config_id=foo', '--filter', 'label=config_id=foo',
'--format', '{{.Names}} {{.Label "container_name"}}'], '--format', '{{.Names}} {{.Label "container_name"}}'],
mock.ANY log=mock.ANY, quiet=False, warn_only=True
), ),
mock.call( mock.call(
['docker', 'ps', '-a', ['docker', 'ps', '-a',
@ -159,7 +159,7 @@ three-12345678 three''', '', 0),
['docker', 'ps', '-a', ['docker', 'ps', '-a',
'--filter', 'label=managed_by=tester', '--filter', 'label=managed_by=tester',
'--format', '{{.Names}} {{.Label "container_name"}}'], '--format', '{{.Names}} {{.Label "container_name"}}'],
mock.ANY log=mock.ANY, quiet=False, warn_only=True
), ),
# rename three from an ephemeral to the static name # rename three from an ephemeral to the static name
mock.call(['docker', 'rename', 'three-12345678', 'three'], mock.call(['docker', 'rename', 'three-12345678', 'three'],
@ -170,7 +170,7 @@ three-12345678 three''', '', 0),
'--filter', 'label=managed_by=tester', '--filter', 'label=managed_by=tester',
'--filter', 'label=config_id=foo', '--filter', 'label=config_id=foo',
'--format', '{{.Names}} {{.Label "container_name"}}'], '--format', '{{.Names}} {{.Label "container_name"}}'],
mock.ANY log=mock.ANY, quiet=False, warn_only=True
), ),
# run one # run one
mock.call( mock.call(
@ -300,7 +300,7 @@ three-12345678 three''', '', 0),
# inspect image centos:7 # inspect image centos:7
mock.call( mock.call(
['docker', 'inspect', '--type', 'image', ['docker', 'inspect', '--type', 'image',
'--format', 'exists', 'centos:7'], mock.ANY, False '--format', 'exists', 'centos:7'], mock.ANY, False, True
), ),
# rm containers not in config # rm containers not in config
mock.call(['docker', 'stop', 'five'], mock.ANY), mock.call(['docker', 'stop', 'five'], mock.ANY),
@ -311,7 +311,7 @@ three-12345678 three''', '', 0),
# check the renamed one, config hasn't changed # check the renamed one, config hasn't changed
mock.call(['docker', 'inspect', '--type', 'container', mock.call(['docker', 'inspect', '--type', 'container',
'--format', '{{index .Config.Labels "config_data"}}', '--format', '{{index .Config.Labels "config_data"}}',
'one'], mock.ANY, False), 'one'], mock.ANY, False, True),
# don't run one, its already running # don't run one, its already running
# run two # run two
mock.call( mock.call(
@ -326,7 +326,7 @@ three-12345678 three''', '', 0),
# rm three, changed config # rm three, changed config
mock.call(['docker', 'inspect', '--type', 'container', mock.call(['docker', 'inspect', '--type', 'container',
'--format', '{{index .Config.Labels "config_data"}}', '--format', '{{index .Config.Labels "config_data"}}',
'three'], mock.ANY, False), 'three'], mock.ANY, False, True),
mock.call(['docker', 'stop', 'three'], mock.ANY), mock.call(['docker', 'stop', 'three'], mock.ANY),
mock.call(['docker', 'rm', 'three'], mock.ANY), mock.call(['docker', 'rm', 'three'], mock.ANY),
# run three # run three
@ -411,12 +411,12 @@ three-12345678 three''', '', 0),
# inspect existing image centos:6 # inspect existing image centos:6
mock.call( mock.call(
['docker', 'inspect', '--type', 'image', ['docker', 'inspect', '--type', 'image',
'--format', 'exists', 'centos:6'], mock.ANY, False '--format', 'exists', 'centos:6'], mock.ANY, False, True
), ),
# inspect and pull missing image centos:7 # inspect and pull missing image centos:7
mock.call( mock.call(
['docker', 'inspect', '--type', 'image', ['docker', 'inspect', '--type', 'image',
'--format', 'exists', 'centos:7'], mock.ANY, False '--format', 'exists', 'centos:7'], mock.ANY, False, True
), ),
mock.call( mock.call(
['docker', 'pull', 'centos:7'], mock.ANY ['docker', 'pull', 'centos:7'], mock.ANY