From 971b64deaad8f3339f12e7bff0558c0a93051e62 Mon Sep 17 00:00:00 2001 From: Matthieu Huin Date: Tue, 27 Apr 2021 20:25:08 +0200 Subject: [PATCH] Improve logging and CLI output Logging was incomplete, and unhelpful in case of an exception. Add also a log_file parameter to the configuration file, so that CLI actions can be logged to a file for audit. Change-Id: Ifa7a2f2828fa38be8879a4a9c64fe948b95d5fb8 --- doc/source/examples/.zuul.conf | 3 ++ zuulclient/cmd/__init__.py | 84 +++++++++++++++++++++++++++------- zuulclient/utils/__init__.py | 6 +-- 3 files changed, 73 insertions(+), 20 deletions(-) diff --git a/doc/source/examples/.zuul.conf b/doc/source/examples/.zuul.conf index 8366f37..459bae6 100644 --- a/doc/source/examples/.zuul.conf +++ b/doc/source/examples/.zuul.conf @@ -13,3 +13,6 @@ url=https://example.com/zuul/ tenant=mytenant # verify_ssl=False auth_token=eyJ0eXAiOiJKV1QiLCJhbGciOiJIUzI1NiJ9 +# the path must be writable by the user. +log_file=/path/to/log +log_level=DEBUG \ No newline at end of file diff --git a/zuulclient/cmd/__init__.py b/zuulclient/cmd/__init__.py index 60664c5..4628085 100644 --- a/zuulclient/cmd/__init__.py +++ b/zuulclient/cmd/__init__.py @@ -99,6 +99,12 @@ class ZuulClient(): def parseArguments(self, args=None): self.parser = self.createParser() self.args = self.parser.parse_args(args) + if ( + (self.args.zuul_url and self.args.zuul_config) or + (not self.args.zuul_url and not self.args.zuul_config) + ): + raise ArgumentException( + 'Either specify --zuul-url or use a config file') if not getattr(self.args, 'func', None): self.parser.print_help() sys.exit(1) @@ -139,9 +145,31 @@ class ZuulClient(): "Unable to locate config file in %s" % locations) def setup_logging(self): - """Client logging does not rely on conf file""" + config_args = dict( + format='%(levelname)-8s - %(message)s' + ) if self.args.verbose: - logging.basicConfig(level=logging.DEBUG) + config_args['level'] = logging.DEBUG + else: + config_args['level'] = logging.ERROR + # set logging across all components (urllib etc) + logging.basicConfig(**config_args) + if self.args.zuul_config and\ + self.args.zuul_config in self.config.sections(): + zuul_conf = self.args.zuul_config + log_file = get_default(self.config, + zuul_conf, 'log_file', None) + if log_file is not None: + fh = logging.FileHandler(log_file) + f_loglevel = get_default(self.config, + zuul_conf, 'log_level', 'INFO') + fh.setLevel(getattr(logging, f_loglevel, 'INFO')) + f_formatter = logging.Formatter( + fmt='%(asctime)s %(name)s %(levelname)-8s - %(message)s', + datefmt='%x %X' + ) + fh.setFormatter(f_formatter) + self.log.addHandler(fh) def _main(self, args=None): # TODO make func return specific return codes @@ -161,15 +189,21 @@ class ZuulClient(): print() raise if ret: + self.log.info('Command %s completed ' + 'successfully' % self.args.func.__name__) return 0 else: + self.log.error('Command %s completed ' + 'with error(s)' % self.args.func.__name__) return 1 def main(self): try: sys.exit(self._main()) except Exception as e: - self.log.error(e) + self.log.exception( + 'Failed with the following exception: %s ' % e + ) sys.exit(1) def _check_tenant_scope(self, client): @@ -225,7 +259,7 @@ class ZuulClient(): node_hold_expiration = self.args.node_hold_expiration client = self.get_client() self._check_tenant_scope(client) - r = client.autohold( + kwargs = dict( tenant=self.tenant(), project=self.args.project, job=self.args.job, @@ -234,6 +268,8 @@ class ZuulClient(): reason=self.args.reason, count=self.args.count, node_hold_expiration=node_hold_expiration) + self.log.info('Invoking autohold with arguments: %s' % kwargs) + r = client.autohold(**kwargs) return r def add_autohold_delete_subparser(self, subparsers): @@ -249,7 +285,12 @@ class ZuulClient(): def autohold_delete(self): client = self.get_client() self._check_tenant_scope(client) - return client.autohold_delete(self.args.id, self.tenant()) + kwargs = dict( + id=self.args.id, + tenant=self.tenant() + ) + self.log.info('Invoking autohold-delete with arguments: %s' % kwargs) + return client.autohold_delete(**kwargs) def add_autohold_info_subparser(self, subparsers): cmd_autohold_info = subparsers.add_parser( @@ -337,11 +378,14 @@ class ZuulClient(): def enqueue(self): client = self.get_client() self._check_tenant_scope(client) - r = client.enqueue( + kwargs = dict( tenant=self.tenant(), pipeline=self.args.pipeline, project=self.args.project, - change=self.args.change) + change=self.args.change + ) + self.log.info('Invoking enqueue with arguments: %s' % kwargs) + r = client.enqueue(**kwargs) return r def add_enqueue_ref_subparser(self, subparsers): @@ -372,13 +416,16 @@ class ZuulClient(): def enqueue_ref(self): client = self.get_client() self._check_tenant_scope(client) - r = client.enqueue_ref( + kwargs = dict( tenant=self.tenant(), pipeline=self.args.pipeline, project=self.args.project, ref=self.args.ref, oldrev=self.args.oldrev, - newrev=self.args.newrev) + newrev=self.args.newrev + ) + self.log.info('Invoking enqueue-ref with arguments: %s' % kwargs) + r = client.enqueue_ref(**kwargs) return r def add_dequeue_subparser(self, subparsers): @@ -401,12 +448,15 @@ class ZuulClient(): def dequeue(self): client = self.get_client() self._check_tenant_scope(client) - r = client.dequeue( + kwargs = dict( tenant=self.tenant(), pipeline=self.args.pipeline, project=self.args.project, change=self.args.change, - ref=self.args.ref) + ref=self.args.ref + ) + self.log.info('Invoking dequeue with arguments: %s' % kwargs) + r = client.dequeue(**kwargs) return r def add_promote_subparser(self, subparsers): @@ -424,15 +474,16 @@ class ZuulClient(): def promote(self): client = self.get_client() self._check_tenant_scope(client) - r = client.promote( + kwargs = dict( tenant=self.tenant(), pipeline=self.args.pipeline, - change_ids=self.args.changes) + change_ids=self.args.changes + ) + self.log.info('Invoking promote with arguments: %s' % kwargs) + r = client.promote(**kwargs) return r def get_client(self): - if self.args.zuul_url and self.args.zuul_config: - raise Exception('Either specify --zuul-url or use a config file') if self.args.zuul_url: self.log.debug( 'Using Zuul URL provided as argument to instantiate client') @@ -559,7 +610,7 @@ class ZuulClient(): key = client.get_key(self.tenant(), self.args.project) pubkey_file.write(str.encode(key)) pubkey_file.close() - self.log.debug('Calling openssl') + self.log.debug('Invoking openssl') ciphertext_chunks = encrypt_with_openssl(pubkey_file.name, plaintext, self.log) @@ -644,7 +695,6 @@ class ZuulClient(): def builds(self): if self.args.voting and self.args.non_voting: raise Exception('--voting and --non-voting are mutually exclusive') - self.log.info('Showing the last {} matches.'.format(self.args.limit)) filters = {'limit': self.args.limit, 'skip': self.args.skip} if self.args.project: diff --git a/zuulclient/utils/__init__.py b/zuulclient/utils/__init__.py index d20cc48..acefc34 100644 --- a/zuulclient/utils/__init__.py +++ b/zuulclient/utils/__init__.py @@ -39,7 +39,7 @@ def get_default(config, section, option, default=None, expand_user=False): def encrypt_with_openssl(pubkey_path, plaintext, logger=None): cmd = ['openssl', 'version'] if logger: - logger.debug('calling "%s"' % ' '.join(cmd)) + logger.debug('Invoking "%s"' % ' '.join(cmd)) try: openssl_version = subprocess.check_output( cmd).split()[1] @@ -48,7 +48,7 @@ def encrypt_with_openssl(pubkey_path, plaintext, logger=None): cmd = ['openssl', 'rsa', '-text', '-pubin', '-in', pubkey_path] if logger: - logger.debug('calling "%s"' % ' '.join(cmd)) + logger.debug('Invoking "%s"' % ' '.join(cmd)) p = subprocess.Popen(cmd, stdout=subprocess.PIPE) (stdout, stderr) = p.communicate() @@ -81,7 +81,7 @@ def encrypt_with_openssl(pubkey_path, plaintext, logger=None): '-oaep', '-pubin', '-inkey', pubkey_path] if logger: - logger.debug('calling "%s" with each data chunk:' % ' '.join(cmd)) + logger.debug('Invoking "%s" with each data chunk:' % ' '.join(cmd)) for count in range(chunks): chunk = plaintext[int(count * max_bytes): int((count + 1) * max_bytes)]